Bug #61091 rpl_stop_slave hangs on Windows
Submitted: 8 May 2011 1:57 Modified: 8 May 2011 18:38
Reporter: Vladislav Vaintroub Email Updates:
Status: Can't repeat Impact on me:
None 
Category:MySQL Server: Replication Severity:S2 (Serious)
Version:5.1 bzr OS:Windows
Assigned to: CPU Architecture:Any

[8 May 2011 1:57] Vladislav Vaintroub
Description:
running rpl_stop_slave on Windows (debug compilation) results in timeouts.
This seems to be a side-effect of fix for Bug#56118

H:\bzr\mysql5.1\mysql-test>perl mysql-test-run.pl rpl_stop_slave
Logging: mysql-test-run.pl  rpl_stop_slave
MySQL Version 5.1.58
Checking supported features...
 - skipping ndbcluster
 - SSL connections supported
 - binaries are debug compiled
Collecting tests...
 - adding combinations for rpl
vardir: H:/bzr/mysql5.1/mysql-test/var
Checking leftover processes...
Removing old var directory...
Creating var directory 'H:/bzr/mysql5.1/mysql-test/var'...
Installing system database...
Using server port 64861

==============================================================================

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

worker[1] Using MTR_BUILD_THREAD 300, with reserved ports 13000..13009
rpl.rpl_stop_slave 'mix'                 [ pass ]  604558
rpl.rpl_stop_slave 'row'                 [ skipped ]  Doesn't support --binlog
ormat='row'
worker[1] Trying to dump core for [mysqltest - pid: 8220, winpid: 8220]
worker[1] Trying to dump core for [mysqld.1 - pid: 8012, winpid: 8012]
worker[1] Trying to dump core for [mysqld.2 - pid: 3504, winpid: 3504]
rpl.rpl_stop_slave 'stmt'                [ fail ]  timeout after 900 seconds
        Test ended at 2011-05-08 03:16:42

Test case timeout after 900 seconds

== H:/bzr/mysql5.1/mysql-test/var/log/rpl_stop_slave.log ==
SET GLOBAL debug= 'd,dump_thread_wait_before_send_xid';
[connection slave]
include/restart_slave.inc
BEGIN;
UPDATE t1 SET c2 = 2 WHERE c1 = 1;
[connection master]
BEGIN;
INSERT INTO t1 VALUES(2, 2);
INSERT INTO t2 VALUES(1);
UPDATE t1 SET c2 = 3 WHERE c1 = 1;
COMMIT;
[connection slave1]
STOP SLAVE;
[connection slave]
ROLLBACK;
[connection master]
SET DEBUG_SYNC= 'now SIGNAL signal.continue';
SET DEBUG_SYNC= 'RESET';
[connection slave]
include/wait_for_slave_to_stop.inc

 == H:/bzr/mysql5.1/mysql-test/var/tmp/analyze-timeout-mysqld.1.err ==
SHOW PROCESSLIST;
Id      User    Host    db      Command Time    State   Info
10      root    localhost:65314 NULL    Binlog Dump     476     Has sent all b
log to slave; waiting for binlog to be updated  NULL
11      root    localhost:65438 NULL    Query   0       NULL    SHOW PROCESSLI

 == H:/bzr/mysql5.1/mysql-test/var/tmp/analyze-timeout-mysqld.2.err ==
SHOW PROCESSLIST;
Id      User    Host    db      Command Time    State   Info
6       root    localhost:65059 test    Query   597     NULL    SHOW SLAVE STA
S
7       root    localhost:65060 test    Query   597     Killing slave   STOP S
VE
8       system user             NULL    Connect 899     Queueing master event
 the relay log  NULL
15      system user             NULL    Connect 597     Has read all relay log
waiting for the slave I/O thread to update it   NULL
16      root    localhost:65439 NULL    Query   0       NULL    SHOW PROCESSLI

mysqltest failed but provided no output
The result from queries just before the failure was:
< snip >
SET GLOBAL debug= 'd,dump_thread_wait_before_send_xid';
[connection slave]
include/restart_slave.inc
BEGIN;
UPDATE t1 SET c2 = 2 WHERE c1 = 1;
[connection master]
BEGIN;
INSERT INTO t1 VALUES(2, 2);
INSERT INTO t2 VALUES(1);
UPDATE t1 SET c2 = 3 WHERE c1 = 1;
COMMIT;
[connection slave1]
STOP SLAVE;
[connection slave]
ROLLBACK;
[connection master]
SET DEBUG_SYNC= 'now SIGNAL signal.continue';
SET DEBUG_SYNC= 'RESET';
[connection slave]
include/wait_for_slave_to_stop.inc

How to repeat:
perl mysql-test-run.pl rpl_stop_slave
[8 May 2011 2:07] Vladislav Vaintroub
Correcting myself, it seems to be side-effect of Bug#58546
[8 May 2011 18:38] MySQL Verification Team
Thank you for the bug report. I couldn't repeat with today source tree on Vista 64-bit:

C:\build\mysql-5.1-2011-05-08\mysql-test>perl mysql-test-run.pl rpl_stop_slave
Found handle.exe version 3.42
Logging: mysql-test-run.pl  rpl_stop_slave
110508 15:35:31 [Note] Plugin 'FEDERATED' is disabled.
MySQL Version 5.1.58
Checking supported features...
 - skipping ndbcluster
 - SSL connections supported
 - binaries are debug compiled
Collecting tests...
 - adding combinations for rpl
vardir: C:/build/mysql-5.1-2011-05-08/mysql-test/var
Removing old var directory...
Creating var directory 'C:/build/mysql-5.1-2011-05-08/mysql-test/var'...
Installing system database...
Using server port 55787

==============================================================================

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

worker[1] Using MTR_BUILD_THREAD 300, with reserved ports 13000..13009
rpl.rpl_stop_slave 'mix'                 [ pass ]  10840
rpl.rpl_stop_slave 'row'                 [ skipped ]  Doesn't support --binlog-format='row'
rpl.rpl_stop_slave 'stmt'                [ pass ]   8929
------------------------------------------------------------
The servers were restarted 1 times
Spent 19.769 of 54 seconds executing testcases

Completed: All 2 tests were successful.