MySQL Bugs: #72356: Creating Slave server from mysqldbexport file using mysqldbimport, brokes slave

Bug #72356	Creating Slave server from mysqldbexport file using mysqldbimport, brokes slave
Submitted:	16 Apr 2014 13:01	Modified:	8 Jul 2014 20:01
Reporter:	Shahriyar Rzayev	Email Updates:
Status:	Can't repeat	Impact on me:	None
Category:	MySQL Server: Replication	Severity:	S1 (Critical)
Version:	5.6.10	OS:	Linux (CentOS 6.5)
Assigned to:		CPU Architecture:	Any

Description:
Dear experts, 
can not find any valuable information for this error that's why i have to be report this as a bug report. Maybe it is a bug otherwise please help to resolve this issue.
I will write down all steps that i did:

First of all setup 2 freh new CentOS 6.5 x86_64 on VirtualBox.
After completing installation of linux servers i setup on 2 servers 
MySQL 5.6.10:

mysql> select @@version;
+------------+
| @@version  |
+------------+
| 5.6.10-log |
+------------+
1 row in set (0.00 sec)

Here is my replication related my.cnf portion from
master server:

# BINARY LOGGING #
server_id                      = 1
log_bin                        = /var/lib/mysql/data/mysql-bin
log_bin_index                  = /var/lib/mysql/data/mysql-bin
expire_logs_days               = 14
sync_binlog                    = 1
binlog_format                  = row
gtid-mode                      = on                             
enforce-gtid-consistency       = true           
master-info-repository         = TABLE            
relay-log-info-repository      = TABLE         
#slave-parallel-workers         = 2               
binlog-checksum                = CRC32                  
master-verify-checksum         = 1                
slave-sql-verify-checksum      = 1             
binlog-rows-query-log_events   = 1
log_slave_updates              = 1

Here is from slave server:

# BINARY LOGGING #

server_id                      = 2
log_bin                        = /var/lib/mysql/data/mysql-bin
log_bin_index                  = /var/lib/mysql/data/mysql-bin
expire_logs_days               = 14
sync_binlog                    = 1
binlog_format                  = row
relay_log                      = /var/lib/mysql/data/mysql-relay-bin
log_slave_updates              = 1
read_only                      = 1
gtid-mode                      = on
enforce-gtid-consistency       = true
master-info-repository         = TABLE
relay-log-info-repository      = TABLE
slave-parallel-workers         = 2
binlog-checksum                = CRC32
master-verify-checksum         = 1
slave-sql-verify-checksum      = 1
binlog-rows-query-log_events   = 1

Created in Master server following users:

CREATE USER 'repl'@'%' IDENTIFIED BY '$slavepass45#';	
GRANT REPLICATION SLAVE,REPLICATION CLIENT ON *.* TO 'repl'@'%';

CREATE USER 'remote'@'%' IDENTIFIED BY '12345';	
grant all on *.* to 'remote'@'%' with grant option;

Created in Slave server following user:

CREATE USER 'remote'@'%' IDENTIFIED BY '12345';	
grant all on *.* to 'remote'@'%' with grant option;

After all installed MySQL Utilities on both servers:

wget http://dev.mysql.com/get/Downloads/MySQLGUITools/mysql-utilities-1.4.2-1.el6.noarch.rpm

wget http://dev.mysql.com/get/Downloads/Connector-Python/mysql-connector-python-1.1.6-1.el6.noa...

rpm -ivh mysql-connector-python-1.1.6-1.el6.noarch.rpm

rpm -ivh mysql-utilities-1.4.2-1.el6.noarch.rpm

Used mysqldbexport to generate dump and slave related commands in file:

mysqldbexport --server=remote:12345@192.168.1.55:3306 --export=both --rpl=master --all --output-file /home/export5.sql --rpl-user=repl:$slavepass45# -vvv --bulk-insert --locking=snapshot

After all used mysqldbimport to import a dump and to start slave:

mysql> reset master;

[root@linuxsrv2 mysql]# mysqldbimport --server=remote:12345@192.168.1.66:3306 /home/export5.sql
.
.
done

But:

mysql> show slave status\G
*************************** 1. row ***************************
               Slave_IO_State: Waiting for master to send event
                  Master_Host: 192.168.1.55
                  Master_User: repl
                  Master_Port: 3306
                Connect_Retry: 60
              Master_Log_File: mysql-bin.000003
          Read_Master_Log_Pos: 5458132
               Relay_Log_File: mysql-relay-bin.000001
                Relay_Log_Pos: 4
        Relay_Master_Log_File: 
             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: 1593
                   Last_Error: Failed during slave workers initialization
                 Skip_Counter: 0
          Exec_Master_Log_Pos: 0
              Relay_Log_Space: 1440
              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: NULL
Master_SSL_Verify_Server_Cert: No
                Last_IO_Errno: 0
                Last_IO_Error: 
               Last_SQL_Errno: 1593
               Last_SQL_Error: Failed during slave workers initialization
  Replicate_Ignore_Server_Ids: 
             Master_Server_Id: 1
                  Master_UUID: 5fbe17b3-c4a6-11e3-852e-080027b935e7
             Master_Info_File: mysql.slave_master_info
                    SQL_Delay: 0
          SQL_Remaining_Delay: NULL
      Slave_SQL_Running_State: 
           Master_Retry_Count: 86400
                  Master_Bind: 
      Last_IO_Error_Timestamp: 
     Last_SQL_Error_Timestamp: 140416 17:15:18
               Master_SSL_Crl: 
           Master_SSL_Crlpath: 
           Retrieved_Gtid_Set: 
            Executed_Gtid_Set: 5fbe17b3-c4a6-11e3-852e-080027b935e7:1-95
                Auto_Position: 1
1 row in set (0.00 sec)

Last portion from error log:

2014-04-16 11:00:33 2746 [Note] /usr/sbin/mysqld: ready for connections.
Version: '5.6.10-log'  socket: '/var/lib/mysql/mysql.sock'  port: 3306  MySQL Community Server (GPL)
2014-04-16 17:14:26 2746 [Note] GTID_PURGED was changed from '' to '5fbe17b3-c4a6-11e3-852e-080027b935e7:1-95'.
2014-04-16 17:14:26 2746 [Note] GTID_EXECUTED was changed from '' to '5fbe17b3-c4a6-11e3-852e-080027b935e7:1-95'.
2014-04-16 17:14:27 2746 [Note] 'CHANGE MASTER TO executed'. Previous state master_host='', master_port= 3306, master_log_file='', master_log_pos= 4, master_bind=''. New state master_host='192.168.1.55', master_port= 3306, master_log_file='', master_log_pos= 4, master_bind=''.
2014-04-16 17:14:27 2746 [Warning] Storing MySQL user name or password information in the master.info repository is not secure and is therefore not recommended. Please see the MySQL Manual for more about this issue and possible alternatives.
2014-04-16 17:14:27 2746 [Note] Slave I/O thread: connected to master 'repl@192.168.1.55:3306',replication started in log 'FIRST' at position 4
2014-04-16 17:15:18 2746 [ERROR] Error writing relay log configuration.
2014-04-16 17:15:18 2746 [ERROR] Slave SQL: Failed during slave workers initialization, Error_code: 1593

autocommit is enabled:

mysql> select @@global.autocommit;
+---------------------+
| @@global.autocommit |
+---------------------+
|                   1 |
+---------------------+
1 row in set (0.00 sec)

How to repeat:
All necessary steps are included in Description.

Suggested fix:
Waiting for expert reply

Thank you for the report.

> After all used mysqldbimport to import a dump and to start slave:
>
> mysql> reset master;

Did you run reset master on master? If yes, this is not a bug: reset master deletes all binary logs while dump, created by mysqldbexport points slave to log, which was current at backup time.

No i run "reset master" on slave server:

As shown in documentation:

https://dev.mysql.com/doc/mysql-utilities/1.4/en/ch03s01s01s02.html

Thank you for the feedback.

I just tested: reason for wrong behavior in your case is part of the command:

--rpl-user=repl:$slavepass45# 

Since $ is special symbol shell treats password as variable name. You need to enclose it in apostrophes.

I dont think it is because of this $ sign bash behaviour.
Because i manually edited mysqldbexport generated .sql file and put password manually in apostrophes.
Will check again with and without $ sign in password field.

I checked and got behavior as I described: failure without apostrophes and success without.

But you can send us resulting file, so we can guess why it was generated wrongly.

Export file generated with repl user password inside ''

Attachment: export6.sql (text/x-sql), 269.19 KiB.

Tested as:

mysqldbexport --server=remote:12345@192.168.1.55:3306 --export=both --rpl=master --all --output-file /home/export6.sql --rpl-user=repl:'$slavepass45#' -vvv --bulk-insert --locking=snapshot

Added generated new file as attachment.

After executing:

mysqldbimport --server=remote:12345@192.168.1.66:3306 /home/export6.sql

Got again:

mysql> show slave status\G
*************************** 1. row ***************************
               Slave_IO_State: Waiting for master to send event
                  Master_Host: 192.168.1.55
                  Master_User: repl
                  Master_Port: 3306
                Connect_Retry: 60
              Master_Log_File: mysql-bin.000002
          Read_Master_Log_Pos: 6044494
               Relay_Log_File: mysql-relay-bin.000001
                Relay_Log_Pos: 4
        Relay_Master_Log_File: 
             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: 1593
                   Last_Error: Failed during slave workers initialization
                 Skip_Counter: 0
          Exec_Master_Log_Pos: 0
              Relay_Log_Space: 1026
              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: NULL
Master_SSL_Verify_Server_Cert: No
                Last_IO_Errno: 0
                Last_IO_Error: 
               Last_SQL_Errno: 1593
               Last_SQL_Error: Failed during slave workers initialization
  Replicate_Ignore_Server_Ids: 
             Master_Server_Id: 1
                  Master_UUID: e2ce6f95-c3ed-11e3-807b-0800278b2dc3
             Master_Info_File: mysql.slave_master_info
                    SQL_Delay: 0
          SQL_Remaining_Delay: NULL
      Slave_SQL_Running_State: 
           Master_Retry_Count: 86400
                  Master_Bind: 
      Last_IO_Error_Timestamp: 
     Last_SQL_Error_Timestamp: 140418 00:12:11
               Master_SSL_Crl: 
           Master_SSL_Crlpath: 
           Retrieved_Gtid_Set: 
            Executed_Gtid_Set: e2ce6f95-c3ed-11e3-807b-0800278b2dc3:1-5365
                Auto_Position: 1
1 row in set (0,00 sec)

Do you need any other information to related problem??

Thank you for the feedback.

I cannot repeat described behavior even with dump file which you sent. Looks like something wrong in your installation. Please attach full slave error log file.

Slave Server Error Log

Attachment: linuxsrv3.err (application/octet-stream, text), 9.08 KiB.

Writing down any steps that i did again:

On Master Server:

mysql> CREATE USER 'repl'@'%' IDENTIFIED BY '$slavepass45#';
Query OK, 0 rows affected (0,00 sec)

mysql> GRANT REPLICATION SLAVE,REPLICATION CLIENT ON *.* TO 'repl'@'%';
Query OK, 0 rows affected (0,00 sec)

mysql> CREATE USER 'remote'@'%' IDENTIFIED BY '12345';
Query OK, 0 rows affected (0,00 sec)

mysql> grant all on *.* to 'remote'@'%' with grant option;
Query OK, 0 rows affected (0,00 sec)

On SLave Server:

mysql> CREATE USER 'remote'@'%' IDENTIFIED BY '12345';
Query OK, 0 rows affected (0,00 sec)

mysql> grant all on *.* to 'remote'@'%' with grant option;
Query OK, 0 rows affected (0,00 sec)

On Master server:

mysqldbexport --server=remote:12345@192.168.1.55:3306 --export=both --rpl=master --all --output-file /home/export7.sql --rpl-user=repl:'$slavepass45#' -vvv --bulk-insert --locking=snapshot

[root@linuxsrv2 ~]# scp /home/export7.sql root@192.168.1.66:/home
root@192.168.1.66's password: 
export7.sql                    100%  269KB 269.2KB/s   00:00 

On Slave server:

1. Because mysqldbimport wants reset master command.

mysql> reset master;
Query OK, 0 rows affected (0,02 sec)

2. But again i wants reset master:

root@linuxsrv3 ~]# mysqldbimport --server=remote:12345@192.168.1.66:3306 /home/export7.sql
# Source on 192.168.1.66: ... connected.
# Importing definitions from /home/export7.sql.
ERROR: The import operation contains GTID statements that require the global gtid_executed system variable on the target to be empty (no value). The gtid_executed value must be reset by issuing a RESET MASTER command on the target prior to attempting the import operation. Once the global gtid_executed value is cleared, you may retry the import.

3. So again reset master:

mysql> reset master;
Query OK, 0 rows affected (0,05 sec)

4. Again mysqldbimport:

[root@linuxsrv3 ~]# mysqldbimport --server=remote:12345@192.168.1.66:3306 /home/export7.sql
# Source on 192.168.1.66: ... connected.
# Importing definitions from /home/export7.sql.
#...done.

5. Looking at slave status:

mysql> show slave status\G
*************************** 1. row ***************************
               Slave_IO_State: Waiting for master to send event
                  Master_Host: 192.168.1.55
                  Master_User: repl
                  Master_Port: 3306
                Connect_Retry: 60
              Master_Log_File: mysql-bin.000001
          Read_Master_Log_Pos: 2006019
               Relay_Log_File: mysql-relay-bin.000001
                Relay_Log_Pos: 4
        Relay_Master_Log_File: 
             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: 1593
                   Last_Error: Failed during slave workers initialization
                 Skip_Counter: 0
          Exec_Master_Log_Pos: 0
              Relay_Log_Space: 612
              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: NULL
Master_SSL_Verify_Server_Cert: No
                Last_IO_Errno: 0
                Last_IO_Error: 
               Last_SQL_Errno: 1593
               Last_SQL_Error: Failed during slave workers initialization
  Replicate_Ignore_Server_Ids: 
             Master_Server_Id: 1
                  Master_UUID: 3570ff40-c66b-11e3-90b7-0800278b2dc3
             Master_Info_File: mysql.slave_master_info
                    SQL_Delay: 0
          SQL_Remaining_Delay: NULL
      Slave_SQL_Running_State: 
           Master_Retry_Count: 86400
                  Master_Bind: 
      Last_IO_Error_Timestamp: 
     Last_SQL_Error_Timestamp: 140418 01:26:02
               Master_SSL_Crl: 
           Master_SSL_Crlpath: 
           Retrieved_Gtid_Set: 
            Executed_Gtid_Set: 3570ff40-c66b-11e3-90b7-0800278b2dc3:1-5309
                Auto_Position: 1
1 row in set (0,00 sec)

Thank you for the feedback.

Message in the error log "2014-04-18 01:26:02 4304 [ERROR] Error writing relay log configuration." and new how-to-repeat steps showed that something wrong happening when your slave changes configuration.

I assume this is fresh installation? Please try current version 5.6.17 and inform us if the issue still exists.

Yes actually this installation is a fresh installation on Virtualbox machines.
"and new how-to-repeat steps showed that something wrong happening when your slave changes configuration." ---  how to find what is exactly going wrong?

Surely i can test on MySQL 5.6.17 but in fact my production installation is on 5.6.10 and i want to promote new slaves using this approach...

Do you need any other information for debugging this issue?

I am not convinced this is a problem with MySQL Utilities. Can you try your test again but do not use the replication features of the utility? Instead, manually enter the correct commands on the slave.

Also, be sure you do not issue any miscellaneous commands that change data (INSERT, UPDATE, DELETE, CREATE, etc.) on either machine. If you must create a user or something that you do not want replicated (logged in the binary log), turn binary logging off before you issue the command and turn it back on after.

Thank you for the feedback.

Regarding to 5.6.10->5.6.17 issue: this database is about bugs in MySQL code, not about helping users to setup MySQL software properly. We also don't backport bug fixes. So, if this misbehavior is a result of bug in MySQL code, you would have to upgrade anyway. This is why I asked you to test with latest version.

But for fresh installation such an error is indeed strange. Your export file looks fine however. So we need to find out what is wrong on the slave side. Please send us output of SHOW CREATE TABLE mysql.slave_relay_log_info taken on slave.

Will provide master and slave server .cnf files for you.

Master Server my.cnf file

Attachment: master_my.cnf (application/octet-stream, text), 3.38 KiB.

Slave server my.cnf file

Attachment: slave_my.cnf (application/octet-stream, text), 3.37 KiB.

Sveta Smirnova,

Tested again with 5.6.10 and same error.
Here is output of show create table that you want:

CREATE TABLE `slave_relay_log_info` (
  `Number_of_lines` int(10) unsigned NOT NULL COMMENT 'Number of lines in the file or rows in the table. Used to version table definitions.',
  `Relay_log_name` text CHARACTER SET utf8 COLLATE utf8_bin NOT NULL COMMENT 'The name of the current relay log file.',
  `Relay_log_pos` bigint(20) unsigned NOT NULL COMMENT 'The relay log position of the last executed event.',
  `Master_log_name` text CHARACTER SET utf8 COLLATE utf8_bin NOT NULL COMMENT 'The name of the master binary log file from which the events in the relay log file were read.',
  `Master_log_pos` bigint(20) unsigned NOT NULL COMMENT 'The master log position of the last executed event.',
  `Sql_delay` int(11) NOT NULL COMMENT 'The number of seconds that the slave must lag behind the master.',
  `Number_of_workers` int(10) unsigned NOT NULL,
  `Id` int(10) unsigned NOT NULL COMMENT 'Internal Id that uniquely identifies this record.',
  PRIMARY KEY (`Id`)
) ENGINE=InnoDB DEFAULT CHARSET=utf8 STATS_PERSISTENT=0 COMMENT='Relay Log Information'

Dear All i tested with 5.6.17 and there was no such error.
I can't figure out what is wrong with 5.6.10.

This is from 5.6.17:

 CREATE TABLE `slave_relay_log_info` (
  `Number_of_lines` int(10) unsigned NOT NULL COMMENT 'Number of lines in the file or rows in the table. Used to version table definitions.',
  `Relay_log_name` text CHARACTER SET utf8 COLLATE utf8_bin NOT NULL COMMENT 'The name of the current relay log file.',
  `Relay_log_pos` bigint(20) unsigned NOT NULL COMMENT 'The relay log position of the last executed event.',
  `Master_log_name` text CHARACTER SET utf8 COLLATE utf8_bin NOT NULL COMMENT 'The name of the master binary log file from which the events in the relay log file were read.',
  `Master_log_pos` bigint(20) unsigned NOT NULL COMMENT 'The master log position of the last executed event.',
  `Sql_delay` int(11) NOT NULL COMMENT 'The number of seconds that the slave must lag behind the master.',
  `Number_of_workers` int(10) unsigned NOT NULL,
  `Id` int(10) unsigned NOT NULL COMMENT 'Internal Id that uniquely identifies this record.',
  PRIMARY KEY (`Id`)
) ENGINE=InnoDB DEFAULT CHARSET=utf8 STATS_PERSISTENT=0 COMMENT='Relay Log Information'

Thank you for the feedback.

Closed as "Can't repeat", because the issue is not repeatable with 5.6.17. For 5.6.10 try to use relay-log-info-repository   and master-info-repository  set to FILE