| Bug #50095 | Multi statement including CREATE EVENT causes rotten binlog entry | ||
|---|---|---|---|
| Submitted: | 5 Jan 2010 18:52 | Modified: | 21 Jun 2010 0:53 |
| Reporter: | Matthias Leich | Email Updates: | |
| Status: | Closed | Impact on me: | |
| Category: | MySQL Server: Replication | Severity: | S3 (Non-critical) |
| Version: | 5.1.42, 5.5.99-m3,6.0.14-alpha | OS: | Any |
| Assigned to: | Libing Song | CPU Architecture: | Any |
[6 Jan 2010 13:16]
Matthias Leich
Better test script: ------------------- --source include/master-slave.inc DELIMITER |; CREATE EVENT e1 ON SCHEDULE EVERY 1 SECOND DO SELECT 9 ; COMMIT | DELIMITER ;| sync_slave_with_master; exit; The entry within the binlog about CREATE EVENT gets garbage at its end if - CREATE EVENT is followed by another SQL statement - CREATE EVENT and the following statement have to be executed as one command. This bug might be rare in applications of customers. But unfortunately the test tool Random Query Generator (RQG) bundles often several SQL statements into one command. So this bug harms the development of tests with RQG to a significant extend.
[29 Jan 2010 8:25]
Libing Song
Had been fixed by the patch for bug#48321
[8 Mar 2010 12:09]
Matthias Leich
Here is nothing fixed. My tree: revno: 3115 committer: Alexander Nozdrin <alik@sun.com> branch nick: mysql-next-mr timestamp: Sat 2010-03-06 The fix for Bug#48321 is included: mleich@five:/work2/6.0/mysql-next-mr1/mysql-test> bzr log | grep 48321 Bug #48321 CURRENT_USER() incorrectly replicated for DROP/RENAME USER; Bug #48321 CURRENT_USER() incorrectly replicated for DROP/RENAME USER; --source include/master-slave.inc DELIMITER |; CREATE EVENT e1 ON SCHEDULE EVERY 1 SECOND DO SELECT 9 ; COMMIT | DELIMITER ;| sync_slave_with_master; exit; ... Last_Errno 1064 Last_Error Error 'You have an error in your SQL syntax; check the manual that corresponds to your MySQL server version for the right syntax to use near 'Â<8f>Â<8f>Â<8f>Â<8f>Â<8f>Â<8f>Â<8f>Â<8f>e1' at line 1' on query. Default database: 'test'. Query: 'CREATE DEFINER=`root`@`localhost` EVENT e1 ON SCHEDULE EVERY 1 SECOND DO SELECT 9 ;<8f><8f><8f><8f><8f><8f><8f><8f>e1' .... analyze: sync_with_master mysqltest: At line 6: sync_slave_with_master failed: 'select master_pos_wait('master-bin.000001', 271, 300)' returned NULL indicating slave SQL thread failure ... SHOW BINLOG EVENTS IN 'master-bin.000001'; Log_name Pos Event_type Server_id End_log_pos Info master-bin.000001 4 Format_desc 1 107 Server ver: 5.6.99-m4-log, Binlog ver: 4 master-bin.000001 107 Query 1 271 use `test`; CREATE DEFINER=`root`@`localhost` EVENT e1 ON SCHEDULE EVERY 1 SECOND DO SELECT 9 ;<8f><8f><8f><8f><8f><8f><8f><8f>e1 ...
[8 Mar 2010 13:37]
Libing Song
Yes, It is not fixed yet. The patch for bug#48321 has some problems, so it can not be pushed yet. I will fix it separately. Thank you for resetting the status.
[10 Mar 2010 10:38]
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/102855 3368 Li-Bing.Song@sun.com 2010-03-10 Bug #50095 Multi statement including CREATE EVENT causes rotten binlog entry The log event of 'CREATE EVENT' was being binlogged with garbage at the end of the query if 'CREATE EVENT' is followed by another SQL statement and they were executed as one command. for example: DELIMITER |; CREATE EVENT e1 ON EVERY DAY DO SELECT 1; SELECT 'a'; DELIMITER ;| When binlogging 'CREATE EVENT', we always create a new statement with definer and write it into the log event. The new statement is made from cpp_buf(preprocessed buffer). which is not a c string(end with '\0'), but it is copied as a c string. In this patch, cpp_buf is copied with its length.
[28 Mar 2010 8:35]
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/104516 3429 Li-Bing.Song@sun.com 2010-03-28 Bug #50095 Multi statement including CREATE EVENT causes rotten binlog entry The log event of 'CREATE EVENT' was being binlogged with garbage at the end of the query if 'CREATE EVENT' is followed by another SQL statement and they were executed as one command. for example: DELIMITER |; CREATE EVENT e1 ON EVERY DAY DO SELECT 1; SELECT 'a'; DELIMITER ;| When binlogging 'CREATE EVENT', we always create a new statement with definer and write it into the log event. The new statement is made from cpp_buf(preprocessed buffer). which is not a c string(end with '\0'), but it is copied as a c string. In this patch, cpp_buf is copied with its length.
[28 Mar 2010 10:11]
Libing Song
Pushed into mysql-5.1-bugteam and merged into mysql-pe
[6 Apr 2010 8:01]
Bugs System
Pushed into 5.1.46 (revid:sergey.glukhov@sun.com-20100405111026-7kz1p8qlzglqgfmu) (version source revid:li-bing.song@sun.com-20100328083747-6up3olukkc4v7nbz) (merge vers: 5.1.46) (pib:16)
[6 Apr 2010 10:50]
Jon Stephens
Documented issue as follows in the 5.1.46 changelog:
CREATE EVENT statements were padded with garbage characters
when written to the binary log, which caused a syntax error
when trying to read from the log.
Set NM status, waiting for 5.5+ merges.
[28 May 2010 5:52]
Bugs System
Pushed into mysql-next-mr (revid:alik@sun.com-20100524190136-egaq7e8zgkwb9aqi) (version source revid:alik@sun.com-20100422150750-vp0n37kp9ywq5ghf) (pib:16)
[28 May 2010 6:21]
Bugs System
Pushed into 6.0.14-alpha (revid:alik@sun.com-20100524190941-nuudpx60if25wsvx) (version source revid:alik@sun.com-20100422150658-fkhgnwwkyugtxrmu) (merge vers: 6.0.14-alpha) (pib:16)
[28 May 2010 6:49]
Bugs System
Pushed into 5.5.5-m3 (revid:alik@sun.com-20100524185725-c8k5q7v60i5nix3t) (version source revid:alexey.kopytov@sun.com-20100403173551-52r97erqowlqwkon) (merge vers: 5.5.4-m3) (pib:16)
[3 Jun 2010 10:34]
Jon Stephens
Updated changelog entry to read:
When a CREATE EVENT statement was followed by an additional
statement and the statements were executed together as a single
statement, the CREATE EVENT statement was padded with "garbage"
characters when written to the binary log, which led to a syntax
error when trying to read back from the log.
Also documented in the 5.5.5 and 6.0.14 changelogs.
Closed.
[17 Jun 2010 11:53]
Bugs System
Pushed into 5.1.47-ndb-7.0.16 (revid:martin.skold@mysql.com-20100617114014-bva0dy24yyd67697) (version source revid:vasil.dimov@oracle.com-20100331130613-8ja7n0vh36a80457) (merge vers: 5.1.46) (pib:16)
[17 Jun 2010 12:30]
Bugs System
Pushed into 5.1.47-ndb-6.2.19 (revid:martin.skold@mysql.com-20100617115448-idrbic6gbki37h1c) (version source revid:martin.skold@mysql.com-20100609211156-tsac5qhw951miwtt) (merge vers: 5.1.46-ndb-6.2.19) (pib:16)
[17 Jun 2010 13:18]
Bugs System
Pushed into 5.1.47-ndb-6.3.35 (revid:martin.skold@mysql.com-20100617114611-61aqbb52j752y116) (version source revid:vasil.dimov@oracle.com-20100331130613-8ja7n0vh36a80457) (merge vers: 5.1.46) (pib:16)
Description: My script: ========== --disable_abort_on_error --source include/master-slave.inc DELIMITER |; CREATE EVENT e1 ON SCHEDULE EVERY 10 SECOND DO SELECT 1; garbage | DELIMITER ;| connection master; --sync_slave_with_master exit; Result on mysql-next-mr revno: 2954 2010-01-04 Version: 5.5.99-m3 ============================================== ... ./mysql-test-run --mysqld=--binlog-format=row rpl_ml11 ... TEST RESULT TIME (ms) ------------------------------------------------------ ... main.rpl_ml11 [ fail ] Test ended at 2010-01-05 19:01:52 CURRENT_TEST: main.rpl_ml11 === SHOW MASTER STATUS === .... ========================== === SHOW SLAVE STATUS === ... Last_Error Error 'You have an error in your SQL syntax; check the manual that corresponds to your MySQL server version for the right syntax to use near 'e1' at line 1' on query. Default database: 'test'. Query: 'CREATE DEFINER=`root`@`localhost` EVENT e1 ON SCHEDULE EVERY 10 SECOND DO SELECT 1;����������������e1' ... analyze: sync_with_master mysqltest: At line 9: sync_slave_with_master failed: 'select master_pos_wait('master-bin.000001', 278, 300)' returned NULL indicating slave SQL thread failure Why is the outcome of the test bad: =================================== 0. In case the "garbage" does not exist all, the binlog content is: ----------------------------------------- use `test`; CREATE DEFINER=`root`@`localhost` EVENT e1 ON SCHEDULE EVERY 10 SECOND DO SELECT 1 Effect is: ---------- - Event gets created - Replication does not stop 1. In case the line direct before "garbage" is: -------------------------------------------- CREATE EVENT e1 ON SCHEDULE EVERY 10 SECOND DO SELECT 1; Binlog content is: ------------------ use `test`; CREATE DEFINER=`root`@`localhost` EVENT e1 ON SCHEDULE EVERY 10 SECOND DO SELECT 1;����������������e1 <== There is garbage at line end Effect is: ---------- - Event gets created - Error 1064 for "garbage" - Replication stops 2. Line direct before "garbage" is: -------------------------------- CREATE PROCEDURE p1 () SELECT 1; Binlog content is: ------------------ use `test`; CREATE DEFINER=`root`@`localhost` PROCEDURE `p1`() Effect is: ---------- - Procedure gets created - Error 1064 for "garbage" - Replication does not stop My trees where I observed this bug ================================== - mysql-5.1-bugteam revno: 3302 2009-12-31 Version: 5.1.42 - mysql-next-mr revno: 2954 2010-01-04 Version: 5.5.99-m3 - mysql-6.0-codebase-bugfixing revno: 3806 2010-01-04 Version: 6.0.14-alpha - All versions were generated with ./BUILD/compile-pentium64-debug-max How to repeat: See above