Tuesday, May 02, 2006

Event scheduler out of control?

I tried to test (once more) the event scheduler of MySQL 5.1.9 on Windows and experienced a very strange behaviour:
CREATE TABLE  `tt` (
   `id` int(10) unsigned NOT NULL auto_increment,
   `d` int(10) unsigned NOT NULL,
   `ts` timestamp NOT NULL,
   PRIMARY KEY (`id`)
) ENGINE=InnoDB DEFAULT CHARSET=utf8;

DELIMITER //

DROP EVENT insertIntoTT //

CREATE EVENT insertIntoTT
ON SCHEDULE EVERY 5 SECOND
STARTS current_timestamp + INTERVAL 5 SECOND
DO
BEGIN
  insert into tt (d) values (floor(rand() * 100));
END //

DELIMITER ;

After a while, I found this content in table tt:
mysql> select * from tt;
+-----+----+---------------------+
| id  | d  | ts                  |
+-----+----+---------------------+
| 1   | 83 | 2006-05-02 07:40:20 |
| 2   | 35 | 2006-05-02 07:40:25 |
| 3   | 66 | 2006-05-02 07:40:25 |
| 4   | 68 | 2006-05-02 07:40:25 |
| 5   | 82 | 2006-05-02 07:40:25 |
| 6   | 50 | 2006-05-02 07:40:25 |
| 7   | 44 | 2006-05-02 07:40:30 |
| 8   | 14 | 2006-05-02 07:40:30 |
| 9   | 79 | 2006-05-02 07:40:30 |
| 10  | 94 | 2006-05-02 07:40:30 |
| 11  | 75 | 2006-05-02 07:40:30 |
| 12  | 35 | 2006-05-02 07:40:30 |
| 13  | 90 | 2006-05-02 07:40:30 |
| 14  | 88 | 2006-05-02 07:40:30 |
| 15  | 13 | 2006-05-02 07:40:30 |
| 16  | 44 | 2006-05-02 07:40:30 |
| 17  | 21 | 2006-05-02 07:40:30 |
| 18  | 16 | 2006-05-02 07:40:30 |
| 19  | 56 | 2006-05-02 07:40:30 |
| 20  | 76 | 2006-05-02 07:40:30 |
| 21  | 54 | 2006-05-02 07:40:30 |
| 22  | 81 | 2006-05-02 07:40:30 |
| 23  | 88 | 2006-05-02 07:40:30 |
| 24  | 38 | 2006-05-02 07:40:30 |
| 25  | 66 | 2006-05-02 07:40:30 |
| 26  | 59 | 2006-05-02 07:40:30 |
| 27  | 39 | 2006-05-02 07:40:30 |
| 28  | 60 | 2006-05-02 07:40:30 |
| 29  | 25 | 2006-05-02 07:40:30 |
| 30  | 89 | 2006-05-02 07:40:30 |
| 31  | 9  | 2006-05-02 07:40:30 |
| 32  | 19 | 2006-05-02 07:40:30 |
| 33  | 10 | 2006-05-02 07:40:30 |
| 34  | 36 | 2006-05-02 07:40:30 |
| 35  | 90 | 2006-05-02 07:40:30 |
| 36  | 84 | 2006-05-02 07:40:30 |
| 37  | 93 | 2006-05-02 07:40:30 |
| 38  | 55 | 2006-05-02 07:40:30 |
| 39  | 36 | 2006-05-02 07:40:30 |
| 40  | 58 | 2006-05-02 07:40:31 |
| 41  | 23 | 2006-05-02 07:40:35 |
| 42  | 81 | 2006-05-02 07:40:35 |
| 43  | 80 | 2006-05-02 07:40:35 |
| 44  | 97 | 2006-05-02 07:40:35 |
| 45  | 88 | 2006-05-02 07:40:35 |
| 46  | 90 | 2006-05-02 07:40:35 |
| 47  | 26 | 2006-05-02 07:40:35 |
| 48  | 5  | 2006-05-02 07:40:35 |
| 49  | 88 | 2006-05-02 07:40:35 |
| 50  | 66 | 2006-05-02 07:40:35 |
| 51  | 8  | 2006-05-02 07:40:35 |
| 52  | 83 | 2006-05-02 07:40:35 |
| 53  | 33 | 2006-05-02 07:40:35 |
| 54  | 59 | 2006-05-02 07:40:35 |
| 55  | 38 | 2006-05-02 07:40:35 |
| 56  | 54 | 2006-05-02 07:40:35 |
| 57  | 99 | 2006-05-02 07:40:35 |
| 58  | 76 | 2006-05-02 07:40:35 |
| 59  | 22 | 2006-05-02 07:40:35 |
| 60  | 27 | 2006-05-02 07:40:35 |
| 61  | 8  | 2006-05-02 07:40:35 |
| 62  | 1  | 2006-05-02 07:40:35 |
| 63  | 25 | 2006-05-02 07:40:35 |
| 64  | 62 | 2006-05-02 07:40:35 |
| 65  | 78 | 2006-05-02 07:40:35 |
| 66  | 45 | 2006-05-02 07:40:35 |
| 67  | 35 | 2006-05-02 07:40:35 |
| 68  | 80 | 2006-05-02 07:40:35 |
| 69  | 36 | 2006-05-02 07:40:35 |
| 70  | 80 | 2006-05-02 07:40:35 |
| 71  | 38 | 2006-05-02 07:40:35 |
| 72  | 89 | 2006-05-02 07:40:35 |
| 73  | 73 | 2006-05-02 07:40:35 |
| 74  | 39 | 2006-05-02 07:40:35 |
| 75  | 19 | 2006-05-02 07:40:35 |
| 76  | 19 | 2006-05-02 07:40:36 |
| 77  | 81 | 2006-05-02 07:40:36 |
| 78  | 88 | 2006-05-02 07:40:40 |
| 79  | 42 | 2006-05-02 07:40:40 |
| 80  | 84 | 2006-05-02 07:40:40 |
| 81  | 38 | 2006-05-02 07:40:40 |
| 82  | 81 | 2006-05-02 07:40:40 |
| 83  | 30 | 2006-05-02 07:40:40 |
| 84  | 50 | 2006-05-02 07:40:40 |
| 85  | 2  | 2006-05-02 07:40:40 |
| 86  | 1  | 2006-05-02 07:40:40 |
| 87  | 42 | 2006-05-02 07:40:40 |
| 88  | 48 | 2006-05-02 07:40:40 |
| 89  | 57 | 2006-05-02 07:40:40 |
| 90  | 81 | 2006-05-02 07:40:40 |
| 91  | 78 | 2006-05-02 07:40:40 |
| 92  | 87 | 2006-05-02 07:40:40 |
| 93  | 42 | 2006-05-02 07:40:40 |
| 94  | 91 | 2006-05-02 07:40:40 |
| 95  | 70 | 2006-05-02 07:40:40 |
| 96  | 22 | 2006-05-02 07:40:40 |
| 97  | 38 | 2006-05-02 07:40:40 |
| 98  | 69 | 2006-05-02 07:40:40 |
| 99  | 70 | 2006-05-02 07:40:40 |
| 100 | 88 | 2006-05-02 07:40:40 |
| 101 | 71 | 2006-05-02 07:40:40 |
| 102 | 31 | 2006-05-02 07:40:40 |
| 103 | 85 | 2006-05-02 07:40:40 |
| 104 | 76 | 2006-05-02 07:40:40 |
| 105 | 63 | 2006-05-02 07:40:40 |
| 106 | 30 | 2006-05-02 07:40:40 |
| 107 | 3  | 2006-05-02 07:40:40 |
| 108 | 68 | 2006-05-02 07:40:40 |
| 109 | 72 | 2006-05-02 07:40:40 |
| 110 | 97 | 2006-05-02 07:40:40 |
| 111 | 13 | 2006-05-02 07:40:40 |
| 112 | 15 | 2006-05-02 07:40:40 |
| 113 | 78 | 2006-05-02 07:40:40 |
| 114 | 86 | 2006-05-02 07:40:40 |
| 115 | 36 | 2006-05-02 07:40:41 |
| 116 | 66 | 2006-05-02 07:40:45 |
| 117 | 61 | 2006-05-02 07:40:45 |
| 118 | 51 | 2006-05-02 07:40:45 |
| 119 | 15 | 2006-05-02 07:40:45 |
| 120 | 61 | 2006-05-02 07:40:45 |
| 121 | 2  | 2006-05-02 07:40:45 |
| 122 | 68 | 2006-05-02 07:40:45 |
| 123 | 78 | 2006-05-02 07:40:45 |
| 124 | 25 | 2006-05-02 07:40:45 |
| 125 | 35 | 2006-05-02 07:40:45 |
| 126 | 42 | 2006-05-02 07:40:45 |
| 127 | 47 | 2006-05-02 07:40:45 |
| 128 | 51 | 2006-05-02 07:40:45 |
| 129 | 56 | 2006-05-02 07:40:45 |
| 130 | 70 | 2006-05-02 07:40:45 |
| 131 | 21 | 2006-05-02 07:40:45 |
| 132 | 39 | 2006-05-02 07:40:45 |
| 133 | 75 | 2006-05-02 07:40:45 |
| 134 | 99 | 2006-05-02 07:40:45 |
| 135 | 12 | 2006-05-02 07:40:45 |
| 136 | 5  | 2006-05-02 07:40:45 |
| 137 | 31 | 2006-05-02 07:40:45 |
| 138 | 82 | 2006-05-02 07:40:45 |
| 139 | 58 | 2006-05-02 07:40:45 |
| 140 | 85 | 2006-05-02 07:40:45 |
| 141 | 93 | 2006-05-02 07:40:45 |
| 142 | 53 | 2006-05-02 07:40:45 |
| 143 | 25 | 2006-05-02 07:40:45 |
| 144 | 11 | 2006-05-02 07:40:45 |
| 145 | 19 | 2006-05-02 07:40:45 |
| 146 | 6  | 2006-05-02 07:40:45 |
| 147 | 14 | 2006-05-02 07:40:45 |
| 148 | 93 | 2006-05-02 07:40:45 |
| 149 | 64 | 2006-05-02 07:40:45 |
| 150 | 83 | 2006-05-02 07:40:45 |
| 151 | 65 | 2006-05-02 07:40:45 |
| 152 | 17 | 2006-05-02 07:40:45 |
| 153 | 35 | 2006-05-02 07:40:46 |
| 154 | 63 | 2006-05-02 07:40:50 |
| 155 | 51 | 2006-05-02 07:40:50 |
+-----+----+---------------------+
155 rows in set (0.00 sec)

Instead of inserting one row every 5 seconds, MySQL inserted 155 rows in 30 seconds. Can anybody else experience something like this?
Posted by at

4 comments:

Anonymous said...

Hi Markus,
the problem is known - Bug #19170. The fix came too late in the build cycle of 5.1.9 and thus was not incorporated into the release. 5.1.10 which will come soon won't have this defect.

16:36
Anonymous said...

very strange. I'd post it to bugs DB after a quick search for similar ...

Cheers,

Jay

17:33
Markus Popp said...

That's good to know, thanks! I wasn't absolutely sure whether it's caused by my installation or whether it's a general problem - so now as the bug is reported and about to be fixed, that's fine for me.

18:16
Markus Popp said...

Hi Sheeri,

great that you've also 5.1 installed. There are still some rough edges, but (at least usually) they get smoother from version to version. This bug here is a little exception ;-).

Cheers,
Markus

16:14

Post a Comment

Subscribe to: Post Comments (Atom)