Bug #45520 rpl_killed_ddl fails sporadically in pb2
Submitted: 16 Jun 2009 10:20 Modified: 15 Mar 2010 4:20
Reporter: Georgi Kodinov Email Updates:
Status: Closed Impact on me:
None 
Category:Tests: Replication Severity:S3 (Non-critical)
Version:5.0-bugteam, 5.0-main OS:Any
Assigned to: Zhenxing He CPU Architecture:Any
Tags: experimental, pb2, sporadic, test failure, tf54

[16 Jun 2009 10:20] Georgi Kodinov
Description:
The test fails in pb2 as follows : 
rpl_killed_ddl                 [ fail ]

=== SHOW MASTER STATUS ===
---- 1. ----
File	slave-bin.000001
Position	2876
Binlog_Do_DB	
Binlog_Ignore_DB	
==========================

=== SHOW SLAVE STATUS ===
---- 1. ----
Slave_IO_State	Waiting for master to send event
Master_Host	127.0.0.1
Master_User	root
Master_Port	12000
Connect_Retry	1
Master_Log_File	master-bin.000001
Read_Master_Log_Pos	3211
Relay_Log_File	slave-relay-bin.000003
Relay_Log_Pos	3260
Relay_Master_Log_File	master-bin.000001
Slave_IO_Running	Yes
Slave_SQL_Running	No
Replicate_Do_DB	
Replicate_Ignore_DB	
Replicate_Do_Table	
Replicate_Ignore_Table	
Replicate_Wild_Do_Table	
Replicate_Wild_Ignore_Table	
Last_Errno	1317
Last_Error	Query partially completed on the master (error on master: 1317) and was aborted. There is a chance that your master is inconsistent at this point. If you are sure that your master is ok, run this query manually on the slave and then restart the slave with SET GLOBAL SQL_SLAVE_SKIP_COUNTER=1; START SLAVE; . Query: 'DROP FUNCTION IF EXISTS f1'
Skip_Counter	0
Exec_Master_Log_Pos	3122
Relay_Log_Space	4204
Until_Condition	None
Until_Log_File	
Until_Log_Pos	0
Master_SSL_Allowed	No
Master_SSL_CA_File	
Master_SSL_CA_Path	
Master_SSL_Cert	
Master_SSL_Cipher	
Master_SSL_Key	
Seconds_Behind_Master	
=========================

mysqltest: In included file "./include/diff_master_slave.inc": At line 15: could not sync with master ('select master_pos_wait('master-bin.000001', 3211)' returned NULL)

The result from queries just before the failure was:
< snip >
ALTER DATABASE d1
DEFAULT CHARACTER SET = 'utf8';
source include/kill_query.inc;
source include/diff_master_slave.inc;
DROP DATABASE d1;
source include/kill_query.inc;
source include/diff_master_slave.inc;
DROP DATABASE d2;
source include/kill_query.inc;
source include/diff_master_slave.inc;
CREATE FUNCTION f2 () RETURNS INT DETERMINISTIC
RETURN 1;
source include/kill_query.inc;
source include/diff_master_slave.inc;
ALTER FUNCTION f1 SQL SECURITY INVOKER;
source include/kill_query.inc;
source include/diff_master_slave.inc;
DROP FUNCTION IF EXISTS f1;
source include/kill_query.inc;
source include/diff_master_slave.inc;

More results from queries before failure can be found in /export/home4/pb2/build/sb_3-None-1245087279.7/mysql-5.0-bugteam-gcov/mysql-test/var/log/rpl_killed_ddl.log

How to repeat:
Run the pb2 :

http://pb2.norway.sun.com/?template=mysql_show_test_failure&test_failure_id=&test_output_i...

Suggested fix:
Either fix or remove the test case
[2 Jul 2009 13:22] Bernt Marius Johnsen
In my first attempt to run this test, it failed (on a machine with no load). Subsequent attempts succeeded.

TEST                           RESULT         TIME (ms)
-------------------------------------------------------

rpl_killed_ddl                 [ fail ]

mysqltest: In included file "./include/diff_master_slave.inc": At line 18: command "diff_files" failed with error 2

The result from queries just before the failure was:
< snip >
source include/kill_query.inc;
source include/diff_master_slave.inc;
CREATE FUNCTION f2 () RETURNS INT DETERMINISTIC
RETURN 1;
source include/kill_query.inc;
source include/diff_master_slave.inc;
ALTER FUNCTION f1 SQL SECURITY INVOKER;
source include/kill_query.inc;
source include/diff_master_slave.inc;
DROP FUNCTION IF EXISTS f1;
source include/kill_query.inc;
source include/diff_master_slave.inc;
DROP FUNCTION IF EXISTS f2;
source include/kill_query.inc;
source include/diff_master_slave.inc;
--- /export/home/tmp/mysql/bug45520/mysql-test/var/tmp/diff_master.out  2009-07-02 16:17:50.000000000 +0300
+++ /export/home/tmp/mysql/bug45520/mysql-test/var/tmp/diff_slave.out   2009-07-02 16:17:50.000000000 +0300
@@ -1,2 +0,0 @@
-Db     Name    Type    Definer Modified        Created Security_type   Comment
-test   f2      FUNCTION        root@localhost  2009-07-02 16:17:50     2009-07-02 16:17:50     DEFINER 

More results from queries before failure can be found in /export/home/tmp/mysql/bug45520/mysql-test/var/log/rpl_killed_ddl.log

Aborting: rpl_killed_ddl failed in default mode. 
To continue, re-run with '--force'.
Stopping All Servers
skipped 9 bytes from file: socket (3)
skipped 9 bytes from file: socket (3)
[2 Jul 2009 13:36] Bernt Marius Johnsen
Running the test several times (>400) in a row shows that i fails in approx 1 out of 4 times.
[3 Jul 2009 9:11] Bernt Marius Johnsen
rpl_killed_ddl be redesigned. In the current version it cant work reliably even under normal load. Tests have shown it to fail in 5%-25% of the cases depending on the host (with no other load). The test seems to have serious timing problems.

One cause of the problem could be the use of MASTER_POS_WAIT() while at the same time introducing errors on the slave.
[7 Jul 2009 10:13] Rafal Somla
Another failure of this test which  can be seen in many trees:
http://pb2.norway.sun.com/web.py?template=mysql_show_test_failure&test_failure_id=2242279
[10 Jul 2009 10:08] Alexander Nozdrin
Made it experimental due to many failures.
[20 Aug 2009 10:42] Andrei Elkin
Another occurrence:

http://pb2.norway.sun.com/web.py?template=mysql_show_test_failure&test_failure_id=2280547
[22 Sep 2009 10:30] 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/84090

2814 He Zhenxing	2009-09-22
      BUG#45520 rpl_killed_ddl fails sporadically in pb2
      
      This is the patch for 5.0, this is backporting the fix from 5.1
      which makes sure that error_code is not set to ER_SERVER_SHUTDOWN
      or ER_QUERY_INTERRUPTED errors if user specified NOT_KILLED when
      creating the binlog event.
[25 Sep 2009 14:01] Luis Soares
See also: BUG#47638.
[28 Sep 2009 5:43] 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/84782

2814 He Zhenxing	2009-09-28
      BUG#45520 rpl_killed_ddl fails sporadically in pb2
      
      There are three issues that caused rpl_killed_ddl fails sporadically
      in pb2:
      
       1) error_code can be ER_QUERY_INTERRUPTED/ER_SERVER_SHUTDOWN when
          killed_status is NOT_KILLED
       2) DATABASE d2 might do exist because the statement to CREATE or
      ALTER it was killed
       3) because of bug 43353, kill the query that do DROP FUNCTION or
          DROP PROCEDURE can result in SP not found
      
      This patch fixed all above issues by:
       1) Make sure error_code is not set to ER_SERVER_SHUTDOWN or 
          ER_QUERY_INTTERUPTED if killed_status is NOT KILLED
       2) Add IF EXISTS to the DROP DATABASE d2 statement
       3) Temporarily disabled testing DROP FUNCTION/PROCEDURE IF EXISTS.
     @ mysql-test/t/rpl_killed_ddl.test
        DATABASE d2 might not exists, add IF EXITS to the DROP statement
[3 Nov 2009 11:04] Georgi Kodinov
Happens in 5.0-bugteam as well. Changing the target version.
[4 Nov 2009 9:14] 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/89261

2839 Georgi Kodinov	2009-11-04
      Disabled the rpl_killed_ddl test in 5.0 because of bug #45520
[4 Nov 2009 9:17] Bugs System
Pushed into 5.0.88 (revid:joro@sun.com-20091104091355-hpz6dwgkrfmokj3k) (version source revid:joro@sun.com-20091104091322-04s7x1p5yd6kiavf) (merge vers: 5.0.88) (pib:13)
[4 Nov 2009 9:27] Bugs System
Pushed into 5.1.41 (revid:joro@sun.com-20091104092152-qz96bzlf2o1japwc) (version source revid:joro@sun.com-20091104091834-femdl0h50mp7vv1z) (merge vers: 5.1.41) (pib:13)
[11 Nov 2009 6:55] Bugs System
Pushed into 6.0.14-alpha (revid:alik@sun.com-20091110093407-rw5g8dys2baqkt67) (version source revid:alik@sun.com-20091109080109-7dxapd5y5pxlu08w) (merge vers: 6.0.14-alpha) (pib:13)
[11 Nov 2009 7:03] Bugs System
Pushed into 5.5.0-beta (revid:alik@sun.com-20091109115615-nuohp02h8mdrz8m2) (version source revid:alik@sun.com-20091105145905-qen477qntdv20g5o) (merge vers: 5.5.0-beta) (pib:13)
[24 Nov 2009 9:33] 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/91392

2814 He Zhenxing	2009-11-24
      BUG#45520 rpl_killed_ddl fails sporadically in pb2
      
      There are three issues that caused rpl_killed_ddl fails sporadically
      in pb2:
      
       1) thd->clear_error() was not called before create Query event
      if operation is executed successfully.
       2) DATABASE d2 might do exist because the statement to CREATE or
      ALTER it was killed
       3) because of bug 43353, kill the query that do DROP FUNCTION or
          DROP PROCEDURE can result in SP not found
      
      This patch fixed all above issues by:
       1) Called thd->clear_error() if the operation succeeded.
       2) Add IF EXISTS to the DROP DATABASE d2 statement
       3) Temporarily disabled testing DROP FUNCTION/PROCEDURE IF EXISTS.
     @ mysql-test/t/rpl_killed_ddl.test
        DATABASE d2 might not exists, add IF EXITS to the DROP statement
     @ sql/sql_db.cc
        Called thd->clear_error() if the operation succeeded
[9 Dec 2009 6:14] 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/93258

2861 He Zhenxing	2009-12-09
      BUG#45520 rpl_killed_ddl fails sporadically in pb2
      
      There are three issues that caused rpl_killed_ddl fails sporadically
      in pb2:
      
       1) thd->clear_error() was not called before create Query event
      if operation is executed successfully.
       2) DATABASE d2 might do exist because the statement to CREATE or
      ALTER it was killed
       3) because of bug 43353, kill the query that do DROP FUNCTION or
          DROP PROCEDURE can result in SP not found
      
      This patch fixed all above issues by:
       1) Called thd->clear_error() if the operation succeeded.
       2) Add IF EXISTS to the DROP DATABASE d2 statement
       3) Temporarily disabled testing DROP FUNCTION/PROCEDURE IF EXISTS.
     @ mysql-test/t/rpl_killed_ddl.test
        DATABASE d2 might not exists, add IF EXITS to the DROP statement
     @ sql/sql_db.cc
        Called thd->clear_error() if the operation succeeded
[9 Dec 2009 6:26] 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/93259

3252 He Zhenxing	2009-12-09 [merge]
      Merge Bug#45520 fix from 5.0-bugteam
[10 Dec 2009 3:44] 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/93418

2863 He Zhenxing	2009-12-10
      Post fix for bug#45520
     @ mysql-test/include/kill_query.inc
        Error 1034 can be generated when change MyISAM table indexes was interrupted
     @ mysql-test/r/rpl_killed_ddl.result
        table t4 may not exists because the ALTER above was interrupted
     @ mysql-test/t/rpl_killed_ddl.test
        table t4 may not exists because the ALTER above was interrupted
[18 Dec 2009 10:40] Bugs System
Pushed into 5.1.41-ndb-7.1.0 (revid:jonas@mysql.com-20091218102229-64tk47xonu3dv6r6) (version source revid:jonas@mysql.com-20091218095730-26gwjidfsdw45dto) (merge vers: 5.1.41-ndb-7.1.0) (pib:15)
[18 Dec 2009 10:56] Bugs System
Pushed into 5.1.41-ndb-6.2.19 (revid:jonas@mysql.com-20091218100224-vtzr0fahhsuhjsmt) (version source revid:jonas@mysql.com-20091217101452-qwzyaig50w74xmye) (merge vers: 5.1.41-ndb-6.2.19) (pib:15)
[18 Dec 2009 11:11] Bugs System
Pushed into 5.1.41-ndb-6.3.31 (revid:jonas@mysql.com-20091218100616-75d9tek96o6ob6k0) (version source revid:jonas@mysql.com-20091217154335-290no45qdins5bwo) (merge vers: 5.1.41-ndb-6.3.31) (pib:15)
[18 Dec 2009 11:25] Bugs System
Pushed into 5.1.41-ndb-7.0.11 (revid:jonas@mysql.com-20091218101303-ga32mrnr15jsa606) (version source revid:jonas@mysql.com-20091218064304-ezreonykd9f4kelk) (merge vers: 5.1.41-ndb-7.0.11) (pib:15)
[19 Dec 2009 8:30] Bugs System
Pushed into 6.0.14-alpha (revid:alik@sun.com-20091219082307-f3i4fn0tm8trb3c0) (version source revid:alik@sun.com-20091216180721-eoa754i79j4ssd3m) (merge vers: 6.0.14-alpha) (pib:15)
[19 Dec 2009 8:33] Bugs System
Pushed into 5.5.1-m2 (revid:alik@sun.com-20091219082021-f34nq4jytwamozz0) (version source revid:alexey.kopytov@sun.com-20091211164058-ycpe0f20d1c4h1gl) (merge vers: 5.5.0-beta) (pib:15)
[19 Dec 2009 8:37] Bugs System
Pushed into mysql-next-mr (revid:alik@sun.com-20091219082213-nhjjgmphote4ntxj) (version source revid:alik@sun.com-20091216180221-a5ps59gajad3pip9) (pib:15)
[19 Dec 2009 9:46] Jon Stephens
Changes appear to be in testing code only; no user-facing changes to document.

Closed without further action.
[14 Jan 2010 8:27] Bugs System
Pushed into 5.0.90 (revid:joro@sun.com-20100114082402-05fod2h6z9x9wok8) (version source revid:aelkin@mysql.com-20091214144410-630vanwyllvvacad) (merge vers: 5.0.89) (pib:16)
[15 Jan 2010 9:02] Bugs System
Pushed into 5.1.43 (revid:joro@sun.com-20100115085139-qkh0i0fpohd9u9p5) (version source revid:zhenxing.he@sun.com-20091210035142-hf1m9z0q0glhq78e) (merge vers: 5.1.42) (pib:16)
[12 Mar 2010 14:20] Bugs System
Pushed into 5.1.44-ndb-7.0.14 (revid:jonas@mysql.com-20100312135944-t0z8s1da2orvl66x) (version source revid:jonas@mysql.com-20100312115609-woou0te4a6s4ae9y) (merge vers: 5.1.44-ndb-7.0.14) (pib:16)
[12 Mar 2010 14:35] Bugs System
Pushed into 5.1.44-ndb-6.2.19 (revid:jonas@mysql.com-20100312134846-tuqhd9w3tv4xgl3d) (version source revid:jonas@mysql.com-20100312060623-mx6407w2vx76h3by) (merge vers: 5.1.44-ndb-6.2.19) (pib:16)
[12 Mar 2010 14:51] Bugs System
Pushed into 5.1.44-ndb-6.3.33 (revid:jonas@mysql.com-20100312135724-xcw8vw2lu3mijrhn) (version source revid:jonas@mysql.com-20100312103652-snkltsd197l7q2yg) (merge vers: 5.1.44-ndb-6.3.33) (pib:16)
[15 Mar 2010 4:20] Jon Stephens
Closing; see my previous comments.