Bug #43686 ctrl+c terminate a tread interrupt slave replcation
Submitted: 17 Mar 2009 2:52 Modified: 23 Mar 2009 14:44
Reporter: Ivan Tan Email Updates:
Status: Duplicate Impact on me:
None 
Category:MySQL Server: Replication Severity:S1 (Critical)
Version:5.1 OS:Linux (as5u2)
Assigned to: CPU Architecture:Any
Tags: replication

[17 Mar 2009 2:52] Ivan Tan
Description:
autocommit = on
table engine=innodb

you delete records from a table, then you terminate the thread whith ctrl+c.

some records have been deleted, but the slave don't.

How to repeat:
-- --------------------------------------------------
-- master
-- --------------------------------------------------
root:test> select count(1) from test;
+----------+
| count(1) |
+----------+
|  1000000 | 
+----------+
1 row in set (0.00 sec)

root:test> detete from test;

ctrl+c

root:test> select count(1) from test;
+----------+
| count(1) |
+----------+
|   259889 | 
+----------+
1 row in set (0.00 sec)

-- --------------------------------------------------
-- slave
-- --------------------------------------------------

root:test> select count(1) from test;
+----------+
| count(1) |
+----------+
|  1000000 | 
+----------+
1 row in set (0.00 sec)

Suggested fix:
when one terminate a thread, db should be automatically rolled back to its previous state.
[17 Mar 2009 3:19] Ivan Tan
when a thread been killed , the operation didn't rollback.

terrible thing
[17 Mar 2009 3:46] Ivan Tan
http://bugs.mysql.com/bug.php?id=2422
[17 Mar 2009 7:45] Sveta Smirnova
Thank you for the report.

I can not repeat described behavior. Please indicate accurate version of MySQL you use.
[17 Mar 2009 12:03] Zhaoyang Jian
I can repeat it too.

OS:SunOS 5.10 Generic_137138-09
DB:MySQL 5.1.31/32-log Source distribution
binlog_format:MIXED/STATEMENT
tx_isolation:REPEATABLE-READ

[root@dc-5 /tmp]#cat deletetest.sh
#/bin/sh
mysql -uadmin -h127.0.0.1 -pxxx -e"set autocommit=0;delete from test.test;"
[root@dc-5 /tmp]#cat killtest.sh
#/bin/sh
mysqladmin -uroot processlist |grep "admin"|awk '{print $2}'|xargs mysqladmin -uroot kill
[root@dc-5 /tmp]#time ./deletetest.sh &
[1] 6708
[root@dc-5 /tmp]#./killtest.sh
ERROR 1053 (08S01) at line 1: Server shutdown in progress

real    0m2.901s
user    0m0.007s
sys     0m0.007s
[root@dc-5 /tmp]#
[1]+  Exit 1                  time ./deletetest.sh

root@dc-5 : (none) 01:35:43> select count(*) from test.test;
+----------+
| count(*) |
+----------+
|  1000000 |
+----------+
1 row in set (1.71 sec)

root@dc-6 : (none) 01:36:01>  select count(*) from test.test;
+----------+
| count(*) |
+----------+
|  1000000 |
+----------+
1 row in set (1.69 sec)

[root@dc-5 /tmp]#cat deletetest.sh
#/bin/sh
mysql -uadmin -h127.0.0.1 -padmin -e"delete from test.test;"
[root@dc-5 /tmp]#time ./deletetest.sh &
[1] 6722
[root@dc-5 /tmp]#./killtest.sh
[root@dc-5 /tmp]#ERROR 1053 (08S01) at line 1: Server shutdown in progress

real    0m2.462s
user    0m0.006s
sys     0m0.007s

[1]+  Exit 1                  time ./deletetest.sh

root@dc-5 : (none) 01:40:30> select count(*) from test.test;
+----------+
| count(*) |
+----------+
|   887377 |
+----------+
1 row in set (1.66 sec)
root@dc-6 : (none) 01:44:05>  select count(*) from test.test;
+----------+
| count(*) |
+----------+
|  1000000 |
+----------+
1 row in set (1.70 sec)
[17 Mar 2009 12:07] Zhaoyang Jian
i guess Ivan Tan's OS is Redhat 5.2 
:D
[19 Mar 2009 14:11] Zhaoyang Jian
why no action?

no other people repeat it?

http://www.jianzhaoyang.com/database/mysql-51-innodb-transaction-bug
[19 Mar 2009 19:08] Sveta Smirnova
sky jian,

thank you for the feedback.

You kill the mysqld on master, so this case looks like slave just did not get binlog events from master. Please provide output of SHOW SLAVE STATUS \G
[20 Mar 2009 10:52] Zhaoyang Jian
[root@dc-5 /tmp]#cat deletetest.sh 
#/bin/sh
mysql -uadmin -h127.0.0.1 -padmin -e"delete from test.test;"
[root@dc-5 /tmp]#cat killtest.sh 
#/bin/sh
mysqladmin -uroot processlist |grep "admin"|awk '{print $2}'|xargs mysqladmin -uroot kill
[root@dc-5 /tmp]#

Before test:

Master:
root@localhost : test 06:39:39> show master status;
+------------------+----------+--------------+------------------+
| File             | Position | Binlog_Do_DB | Binlog_Ignore_DB |
+------------------+----------+--------------+------------------+
| mysql-bin.002096 |     1741 |              |                  | 
+------------------+----------+--------------+------------------+
1 row in set (0.00 sec)

root@localhost : test 06:40:54> select count(*) from test;
+----------+
| count(*) |
+----------+
|  1000000 | 
+----------+
1 row in set (1.75 sec)

Slave:
1 row in set (1.87 sec)
root@localhost : test 06:40:11> show slave status\G
*************************** 1. row ***************************
               Slave_IO_State: Waiting for master to send event
                  Master_Host: 10.0.38.24
                  Master_User: repl
                  Master_Port: 3306
                Connect_Retry: 60
              Master_Log_File: mysql-bin.002096
          Read_Master_Log_Pos: 1741
               Relay_Log_File: mysql-relay-bin.006993
                Relay_Log_Pos: 251
        Relay_Master_Log_File: mysql-bin.002096
             Slave_IO_Running: Yes
            Slave_SQL_Running: Yes
              Replicate_Do_DB: 
          Replicate_Ignore_DB: 
           Replicate_Do_Table: 
       Replicate_Ignore_Table: 
      Replicate_Wild_Do_Table: 
  Replicate_Wild_Ignore_Table: 
                   Last_Errno: 0
                   Last_Error: 
                 Skip_Counter: 0
          Exec_Master_Log_Pos: 1741
              Relay_Log_Space: 8
              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: 0
Master_SSL_Verify_Server_Cert: No
                Last_IO_Errno: 0
                Last_IO_Error: 
               Last_SQL_Errno: 0
               Last_SQL_Error: 
1 row in set (0.00 sec)

root@localhost : test 06:41:18> select count(*) from test;
+----------+
| count(*) |
+----------+
|  1000000 | 
+----------+
1 row in set (1.75 sec)

Test:
[root@dc-5 /tmp]#time ./deletetest.sh &
[1] 7613
[root@dc-5 /tmp]#./killtest.sh 
[root@dc-5 /tmp]#ERROR 1053 (08S01) at line 1: Server shutdown in progress

real    0m2.633s
user    0m0.006s
sys     0m0.007s

[1]+  Exit 1                  time ./deletetest.sh
[root@dc-5 /tmp]#

After test:

Master:
root@localhost : test 06:41:15> show master status;
+------------------+----------+--------------+------------------+
| File             | Position | Binlog_Do_DB | Binlog_Ignore_DB |
+------------------+----------+--------------+------------------+
| mysql-bin.002096 |     1741 |              |                  | 
+------------------+----------+--------------+------------------+
1 row in set (0.00 sec)

root@localhost : test 06:41:41> select count(*) from test;
+----------+
| count(*) |
+----------+
|   894465 | 
+----------+

Slave:
root@localhost : test 06:41:40> show slave status\G
*************************** 1. row ***************************
               Slave_IO_State: Waiting for master to send event
                  Master_Host: 10.0.38.24
                  Master_User: repl
                  Master_Port: 3306
                Connect_Retry: 60
              Master_Log_File: mysql-bin.002096
          Read_Master_Log_Pos: 1741
               Relay_Log_File: mysql-relay-bin.006993
                Relay_Log_Pos: 251
        Relay_Master_Log_File: mysql-bin.002096
             Slave_IO_Running: Yes
            Slave_SQL_Running: Yes
              Replicate_Do_DB: 
          Replicate_Ignore_DB: 
           Replicate_Do_Table: 
       Replicate_Ignore_Table: 
      Replicate_Wild_Do_Table: 
  Replicate_Wild_Ignore_Table: 
                   Last_Errno: 0
                   Last_Error: 
                 Skip_Counter: 0
          Exec_Master_Log_Pos: 1741
              Relay_Log_Space: 8
              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: 0
Master_SSL_Verify_Server_Cert: No
                Last_IO_Errno: 0
                Last_IO_Error: 
               Last_SQL_Errno: 0
               Last_SQL_Error: 
1 row in set (0.00 sec)

root@localhost : test 06:42:11> select count(*) from test;
+----------+
| count(*) |
+----------+
|  1000000 | 
+----------+
1 row in set (1.74 sec)

It looks like there has no binlog be written at master,but it's data has deleted!
[20 Mar 2009 12:23] Sveta Smirnova
Thank you for the feedback.

This can be same problem as in bug #37926. Please check if binary log is corrupted (`mysqlbinlog mysql-bin.002096` on master).
[21 Mar 2009 9:09] Zhaoyang Jian
no, the binady log is work well,has not be coruppted.
[21 Mar 2009 9:12] Zhaoyang Jian
and i must correct your word,
not kill mysqld, just kill one thread ,the "delete" thread!

and excuse my pool english :)
[23 Mar 2009 14:44] Susanne Ebrecht
This is a duplicate to bug #319 which was split into bug #319 and bug #43217.

At last this is a duplicate of bug #38205
[24 Mar 2009 13:09] Zhaoyang Jian
ok

is there any patch or action for this bug?