MySQL Bugs: #39245: Slave does not stop when using stop slave command

Bug #39245	Slave does not stop when using stop slave command
Submitted:	4 Sep 2008 14:29	Modified:	8 Oct 2008 12:27
Reporter:	Pavel Baranov	Email Updates:
Status:	No Feedback	Impact on me:	None
Category:	MySQL Server: Replication	Severity:	S2 (Serious)
Version:	5.0.37-max-log, 5.0.67	OS:	Linux (REDHAT E 5.0)
Assigned to:		CPU Architecture:	Any
Tags:	replication, stop slave

Description:
Hello guys,

This is what happens when I run stop slave; on 1 of our slaves:

080904 10:14:13 [Note] Slave I/O thread killed while reading event
080904 10:14:13 [Note] Slave I/O thread exiting, read up to log 'node6_bin_log.000031', position 723276949
080904 10:14:13 [Note] Error reading relay log event: slave SQL thread was killed
080904 10:14:13 [Note] Slave SQL thread initialized, starting replication in log 'node6_bin_log.000031' at position 723276949, relay log './ndb05-relay-bin.000095' position: 409329
080904 10:14:13 [Note] Slave I/O thread: connected to master 'replication@10.1.0.106:3306',  replication started in log 'node6_bin_log.000031' at position 723276949

For some reason replication is starting right up ...

my.cnf:

# The following options will be passed to all MySQL clients
[client]
#password       = your_password
port            = 3306
socket          = /tmp/mysql.sock

# Here follows entries for some specific programs

# The MySQL server
[mysqld]
init-connect='SET NAMES utf8'
collation_server=utf8_unicode_ci
character_set_server=utf8

datadir=/mysql/vd1/

skip-name-resolve
skip-slave-start
#relay-log = /mysql/vd-logs/mysql/relay.log
#relay-log-info-file = /mysql/vd-logs/mysql/relay-log.info
#relay-log-index = /mysql/vd-logs/mysql/relay-log.index

max_connections = 800
long_query_time = 2
log_slow_queries= /mysql/vd-logs/slow_queries.sql
#log-queries=/var/log/mysql.log

port            = 3306
socket          = /tmp/mysql.sock
skip-locking
key_buffer = 1024M
max_allowed_packet = 1M
table_cache = 512
sort_buffer_size = 32M
read_buffer_size = 8M
read_rnd_buffer_size = 8M
myisam_sort_buffer_size = 356M
thread_cache_size = 32
query_cache_size = 32M

tmp_table_size = 1280M
max_heap_table_size = 1280M

#myisam_repair_threads = 2

# Try number of CPU's*2 for thread_concurrency
thread_concurrency = 8

# Don't listen on a TCP/IP port at all. This can be a security enhancement,
# if all processes that need to connect to mysqld run on the same host.
# All interaction with mysqld must be made via Unix sockets or named pipes.
# Note that using this option without enabling named pipes on Windows
# (via the "enable-named-pipe" option) will render mysqld useless!
#
#skip-networking

server-id = 5
master-host = 10.1.0.103
master-user = 
master-password = 
master-port = 3306
log-bin=node5_bin_log

innodb_file_per_table
# Uncomment the following if you are using InnoDB tables
innodb_data_home_dir = /mysql/vd1/
innodb_data_file_path = ibdata1:100M;ibdata2:200M;ibdata3:500M:autoextend
innodb_log_group_home_dir = /mysql/vd-logs/
#innodb_log_arch_dir = /usr/local/mysql/data/
# You can set .._buffer_pool_size up to 50 - 80 %
# of RAM but beware of setting memory usage too high

innodb_buffer_pool_size = 10000M
innodb_additional_mem_pool_size = 64M

# Set .._log_file_size to 25 % of buffer pool size
innodb_log_file_size = 1024M
innodb_log_buffer_size = 8M

innodb_flush_log_at_trx_commit = 0 #1 - slow, 2 - fast, 0 - fastest!
#innodb_flush_method = O_DIRECT

#innodb_lock_wait_timeout = 50
innodb_fast_shutdown

[mysqldump]
quick
max_allowed_packet = 16M

[mysql]
no-auto-rehash
# Remove the next comment character if you are not familiar with SQL
#safe-updates

[isamchk]
key_buffer = 256M
sort_buffer_size = 256M
read_buffer = 2M
write_buffer = 2M

[myisamchk]
key_buffer = 1024M
sort_buffer_size = 512M
read_buffer = 32M
write_buffer = 32M

[mysqlhotcopy]
interactive-timeout

thanks

How to repeat:
not sure... it works on other slaves...

Suggested fix:
stop the slave :)

Thank you for the report.

But version 5.0.37 is quite old. Please upgrade to current version 5.0.67, try with it and inform us if the problem still exists.

upgraded to 5.0.67
WARNINGS were shown:
080904 16:26:12 [Warning] The syntax for replication startup options is deprecated and will be removed in MySQL 5.2. Please use 'CHANGE MASTER' instead.
080904 16:26:12 [Warning] Neither --relay-log nor --relay-log-index were used; so replication may break when this MySQL server acts as a slave and has his hostname changed!! Please use '--relay-log=ndb05-relay-bin' to avoid this problem.
080904 16:26:12 [Warning] The syntax for replication startup options is deprecated and will be removed in MySQL 5.2. Please use 'CHANGE MASTER' instead.
080904 16:26:13 [Warning] Neither --relay-log nor --relay-log-index were used; so replication may break when this MySQL server acts as a slave and has his hostname changed!! Please use '--relay-log=ndb05-relay-bin' to avoid this problem.

the problem persists

Thank you for the feedback.

Please try to find what happens on your server:

1. If problem is repeatable every time on the particular slave please stop the server, add option log to my.cnf, start server, start slave, stop slave, examine if slave is restarted and send us general log content.
2. Additionally issue SHOW SLAVE STATUS before stopping slave, remember  Exec_Master_Log_Pos, stop slave, check slave magically restarted and remember new  Exec_Master_Log_Pos. Please send us content of the master binary log file between these 2  Exec_Master_Log_Pos
3. Also, please, send us full error log file.

by sating "option log" you mean error log ?

master binary log between those execs

Attachment: binlog.log (text/plain), 97.36 KiB.

and here is what I did:

mysql> show slave status \G
*************************** 1. row ***************************
             Slave_IO_State: Waiting for master to send event
                Master_Host: 10.1.0.106
                Master_User: replication
                Master_Port: 3306
              Connect_Retry: 60
            Master_Log_File: node6_bin_log.000032
        Read_Master_Log_Pos: 1037658188
             Relay_Log_File: ndb05-relay-bin.000125
              Relay_Log_Pos: 50753
      Relay_Master_Log_File: node6_bin_log.000032
           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: 1037455326
            Relay_Log_Space: 253615
            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: 32
1 row in set (0.00 sec)

mysql> stop slave;
Query OK, 0 rows affected (0.01 sec)

mysql> show slave status \G
*************************** 1. row ***************************
             Slave_IO_State: Waiting for master to send event
                Master_Host: 10.1.0.106
                Master_User: replication
                Master_Port: 3306
              Connect_Retry: 60
            Master_Log_File: node6_bin_log.000032
        Read_Master_Log_Pos: 1037668056
             Relay_Log_File: ndb05-relay-bin.000125
              Relay_Log_Pos: 105331
      Relay_Master_Log_File: node6_bin_log.000032
           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: 1037509904
            Relay_Log_Space: 263771
            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: 28
1 row in set (0.00 sec)

LOG:

080905 11:11:40 [Note] Slave I/O thread killed while reading event
080905 11:11:40 [Note] Slave I/O thread exiting, read up to log 'node6_bin_log.000032', position 1037661777
080905 11:11:40 [Note] Slave SQL thread exiting, replication stopped in log 'node6_bin_log.000032' at position 259
080905 11:11:40 [Note] Slave SQL thread initialized, starting replication in log 'node6_bin_log.000032' at position 259, relay log './ndb05-relay-bin.000125' position: 59414
080905 11:11:40 [Note] Slave I/O thread: connected to master 'replication@10.1.0.106:3306',  replication started in log 'node6_bin_log.000032' at position 1037661777

Thank you for the feedback.

> by sating "option log" you mean error log ?

Not, I meant general query log.

for some reason everything went back to normal :-/

Does this mean, we can close this bug report?

No feedback was provided for this bug for over a month, so it is
being suspended automatically. If you are able to provide the
information that was originally requested, please do so and change
the status of the bug back to "Open".