## Steps to install dbdeployer https://github.com/datacharmer/dbdeployer and binary https://github.com/datacharmer/dbdeployer/releases ushastry@BugCentOS7 rsandbox_5_7_23]$ dbdeployer --version dbdeployer version 1.12.3 ushastry@BugCentOS7 rsandbox_5_7_23]$ cat /etc/*release CentOS Linux release 7.5.1804 (Core) NAME="CentOS Linux" VERSION="7 (Core)" ID="centos" ID_LIKE="rhel fedora" VERSION_ID="7" PRETTY_NAME="CentOS Linux 7 (Core)" ANSI_COLOR="0;31" CPE_NAME="cpe:/o:centos:centos:7" HOME_URL="https://www.centos.org/" BUG_REPORT_URL="https://bugs.centos.org/" CENTOS_MANTISBT_PROJECT="CentOS-7" CENTOS_MANTISBT_PROJECT_VERSION="7" REDHAT_SUPPORT_PRODUCT="centos" REDHAT_SUPPORT_PRODUCT_VERSION="7" CentOS Linux release 7.5.1804 (Core) CentOS Linux release 7.5.1804 (Core) [ushastry@BugCentOS7 Downloads]$ dbdeployer unpack mysql-5.7.23-linux-glibc2.12-x86_64.tar.gz Unpacking tarball mysql-5.7.23-linux-glibc2.12-x86_64.tar.gz to $HOME/opt/mysql/5.7.23 .........100.........200.........300.......375 Renaming directory /home/ushastry/opt/mysql/mysql-5.7.23-linux-glibc2.12-x86_64 to /home/ushastry/opt/mysql/5.7.23 [ushastry@BugCentOS7 Downloads]$ dbdeployer deploy replication 5.7.23 --gtid -c "binlog_format = 'STATEMENT'" -c "slave_parallel_workers = 10" -c skip-slave-start Creating directory /home/ushastry/sandboxes Installing and starting master .. sandbox server started Installing and starting slave1 .. sandbox server started Installing and starting slave2 .. sandbox server started $HOME/sandboxes/rsandbox_5_7_23/initialize_slaves initializing slave 1 initializing slave 2 Replication directory installed in $HOME/sandboxes/rsandbox_5_7_23 run 'dbdeployer usage multiple' for basic instructions' cd $HOME/sandboxes/rsandbox_5_7_23 - followed steps from report $ dbdeployer deploy replication mysql_5.7.23 --gtid \ -c "binlog_format = 'STATEMENT'" \ -c "slave_parallel_workers = 10" \ -c skip-slave-start $ ./s1 -N <<< 'show global variables like "%relay_log_info_repository%"' relay_log_info_repository TABLE $ ./s1 -N <<< 'show global variables like "%relay_log_r%"' relay_log_recovery ON $ ./s1 <<< 'show slave status\G' | grep Auto_Position Auto_Position: 1 Create two schemas and one table per schema for using MTS: $ ./m <<< " create database test_jfg1; create database test_jfg2; create table test_jfg1.t(id int primary key, v int); create table test_jfg2.t(id int primary key, v int)" Stop one slave and insert data on the master using sleep to cause a gap on slave thanks to SBR (the insert will take some time because of the sleep): $ ./s1 <<< "stop slave;"; \ ./m <<< " insert into test_jfg1.t values(1,1); insert into test_jfg1.t values(2,sleep(30)); insert into test_jfg2.t values(1,1)" Start the slave, and because of SBR we expect a gap which we validate by select and show master status. We then crash the OS. $ ./s1 <<< " start slave; do sleep(5); select * from test_jfg1.t; select * from test_jfg2.t; show master status"; \ sudo bash -c "echo c > /proc/sysrq-trigger" id v 1 1 id v 1 1 File Position Binlog_Do_DB Binlog_Ignore_DB Executed_Gtid_Set ^^ OS restarted, restarting MySQL (with ./start_all) [ushastry@BugCentOS7 rsandbox_5_7_23]$ ./start_all # executing 'start' on /home/ushastry/sandboxes/rsandbox_5_7_23 executing 'start' on master ... sandbox server started executing 'start' on slave 1 .. sandbox server started executing 'start' on slave 2 .. sandbox server started - node 1 error log has this cat node1/data/msandbox.err 2018-10-23T11:19:11.550122Z mysqld_safe Logging to '/home/ushastry/sandboxes/rsandbox_5_7_23/node1/data/msandbox.err'. 2018-10-23T11:19:11.637676Z mysqld_safe Starting mysqld daemon with databases from /home/ushastry/sandboxes/rsandbox_5_7_23/node1/data 2018-10-23T11:19:11.671045Z 0 [Warning] Changed limits: max_open_files: 1024 (requested 5000) 2018-10-23T11:19:11.671259Z 0 [Warning] Changed limits: table_open_cache: 431 (requested 2000) 2018-10-23T11:19:12.065527Z 0 [Warning] TIMESTAMP with implicit DEFAULT value is deprecated. Please use --explicit_defaults_for_timestamp server option (see documentation for more details). 2018-10-23T11:19:12.065708Z 0 [Note] --secure-file-priv is set to NULL. Operations related to importing and exporting data are disabled 2018-10-23T11:19:12.065777Z 0 [Note] /home/ushastry/opt/mysql/5.7.23/bin/mysqld (mysqld 5.7.23-log) starting as process 5521 ... 2018-10-23T11:19:12.120582Z 0 [Note] InnoDB: PUNCH HOLE support available 2018-10-23T11:19:12.120640Z 0 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins 2018-10-23T11:19:12.120660Z 0 [Note] InnoDB: Uses event mutexes 2018-10-23T11:19:12.120781Z 0 [Note] InnoDB: GCC builtin __sync_synchronize() is used for memory barrier 2018-10-23T11:19:12.120821Z 0 [Note] InnoDB: Compressed tables use zlib 1.2.3 2018-10-23T11:19:12.120848Z 0 [Note] InnoDB: Using Linux native AIO 2018-10-23T11:19:12.131421Z 0 [Note] InnoDB: Number of pools: 1 2018-10-23T11:19:12.131765Z 0 [Note] InnoDB: Using CPU crc32 instructions 2018-10-23T11:19:12.135575Z 0 [Note] InnoDB: Initializing buffer pool, total size = 128M, instances = 1, chunk size = 128M 2018-10-23T11:19:12.206098Z 0 [Note] InnoDB: Completed initialization of buffer pool 2018-10-23T11:19:12.230691Z 0 [Note] InnoDB: If the mysqld execution user is authorized, page cleaner thread priority can be changed. See the man page of setpriority(). 2018-10-23T11:19:12.254831Z 0 [Note] InnoDB: Highest supported file format is Barracuda. 2018-10-23T11:19:12.294737Z 0 [Note] InnoDB: Creating shared tablespace for temporary tables 2018-10-23T11:19:12.295186Z 0 [Note] InnoDB: Setting file './ibtmp1' size to 12 MB. Physically writing the file full; Please wait ... 2018-10-23T11:19:12.422157Z 0 [Note] InnoDB: File './ibtmp1' size is now 12 MB. 2018-10-23T11:19:12.434633Z 0 [Note] InnoDB: 96 redo rollback segment(s) found. 96 redo rollback segment(s) are active. 2018-10-23T11:19:12.434668Z 0 [Note] InnoDB: 32 non-redo rollback segment(s) are active. 2018-10-23T11:19:12.447167Z 0 [Note] InnoDB: Waiting for purge to start 2018-10-23T11:19:12.502451Z 0 [Note] InnoDB: 5.7.23 started; log sequence number 2588944 2018-10-23T11:19:12.514183Z 0 [Note] InnoDB: Loading buffer pool(s) from /home/ushastry/sandboxes/rsandbox_5_7_23/node1/data/ib_buffer_pool 2018-10-23T11:19:12.514518Z 0 [Note] Plugin 'FEDERATED' is disabled. 2018-10-23T11:19:12.526650Z 0 [Note] InnoDB: Buffer pool(s) load completed at 181023 7:19:12 2018-10-23T11:19:12.598088Z 0 [Warning] Failed to set up SSL because of the following SSL library error: SSL context is not usable without certificate and private key 2018-10-23T11:19:12.598130Z 0 [Note] Server hostname (bind-address): '127.0.0.1'; port: 19025 2018-10-23T11:19:12.598191Z 0 [Note] - '127.0.0.1' resolves to '127.0.0.1'; 2018-10-23T11:19:12.598285Z 0 [Note] Server socket created on IP: '127.0.0.1'. 2018-10-23T11:19:12.644182Z 0 [Note] Event Scheduler: Loaded 0 events 2018-10-23T11:19:12.644614Z 0 [Note] /home/ushastry/opt/mysql/5.7.23/bin/mysqld: ready for connections. Version: '5.7.23-log' socket: '/tmp/mysql_sandbox19025.sock' port: 19025 MySQL Community Server (GPL) 2018-10-23T11:19:21.094826Z 2 [Note] 'CHANGE MASTER TO FOR CHANNEL '' executed'. Previous state master_host='', master_port= 3306, master_log_file='', master_log_pos= 4, master_bind=''. New state master_host='127.0.0.1', master_port= 19024, master_log_file='', master_log_pos= 4, master_bind=''. 2018-10-23T11:19:21.155160Z 4 [Warning] Storing MySQL user name or password information in the master info repository is not secure and is therefore not recommended. Please consider using the USER and PASSWORD connection options for START SLAVE; see the 'START SLAVE Syntax' in the MySQL Manual for more information. 2018-10-23T11:19:21.157394Z 4 [Note] Slave I/O thread for channel '': connected to master 'rsandbox@127.0.0.1:19024',replication started in log 'FIRST' at position 4 2018-10-23T11:19:21.226987Z 5 [Note] Slave SQL thread for channel '' initialized, starting replication in log 'FIRST' at position 0, relay log './mysql-relay.000001' position: 4 2018-10-23T11:22:27.541340Z 5 [Note] Error reading relay log event for channel '': slave SQL thread was killed 2018-10-23T11:22:27.543039Z 5 [Note] Slave SQL thread for channel '' exiting, replication stopped in log 'mysql-bin.000001' at position 4819 2018-10-23T11:22:27.549587Z 4 [Note] Slave I/O thread killed while reading event for channel '' 2018-10-23T11:22:27.549617Z 4 [Note] Slave I/O thread exiting for channel '', read up to log 'mysql-bin.000001', position 4819 2018-10-23T11:26:39.734685Z mysqld_safe Logging to '/home/ushastry/sandboxes/rsandbox_5_7_23/node1/data/msandbox.err'. 2018-10-23T11:26:39.862353Z mysqld_safe Starting mysqld daemon with databases from /home/ushastry/sandboxes/rsandbox_5_7_23/node1/data 2018-10-23T11:26:39.905180Z 0 [Warning] Changed limits: max_open_files: 1024 (requested 5000) 2018-10-23T11:26:39.905555Z 0 [Warning] Changed limits: table_open_cache: 431 (requested 2000) 2018-10-23T11:26:40.109871Z 0 [Warning] TIMESTAMP with implicit DEFAULT value is deprecated. Please use --explicit_defaults_for_timestamp server option (see documentation for more details). 2018-10-23T11:26:40.110031Z 0 [Note] --secure-file-priv is set to NULL. Operations related to importing and exporting data are disabled 2018-10-23T11:26:40.110103Z 0 [Note] /home/ushastry/opt/mysql/5.7.23/bin/mysqld (mysqld 5.7.23-log) starting as process 4001 ... 2018-10-23T11:26:40.128782Z 0 [Note] InnoDB: PUNCH HOLE support available 2018-10-23T11:26:40.128847Z 0 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins 2018-10-23T11:26:40.128865Z 0 [Note] InnoDB: Uses event mutexes 2018-10-23T11:26:40.128883Z 0 [Note] InnoDB: GCC builtin __sync_synchronize() is used for memory barrier 2018-10-23T11:26:40.128899Z 0 [Note] InnoDB: Compressed tables use zlib 1.2.3 2018-10-23T11:26:40.128916Z 0 [Note] InnoDB: Using Linux native AIO 2018-10-23T11:26:40.129932Z 0 [Note] InnoDB: Number of pools: 1 2018-10-23T11:26:40.130181Z 0 [Note] InnoDB: Using CPU crc32 instructions 2018-10-23T11:26:40.134371Z 0 [Note] InnoDB: Initializing buffer pool, total size = 128M, instances = 1, chunk size = 128M 2018-10-23T11:26:40.155212Z 0 [Note] InnoDB: Completed initialization of buffer pool 2018-10-23T11:26:40.159389Z 0 [Note] InnoDB: If the mysqld execution user is authorized, page cleaner thread priority can be changed. See the man page of setpriority(). 2018-10-23T11:26:40.211720Z 0 [Note] InnoDB: Highest supported file format is Barracuda. 2018-10-23T11:26:40.235102Z 0 [Note] InnoDB: Log scan progressed past the checkpoint lsn 2640575 2018-10-23T11:26:40.235200Z 0 [Note] InnoDB: Doing recovery: scanned up to log sequence number 2640584 2018-10-23T11:26:40.235236Z 0 [Note] InnoDB: Database was not shutdown normally! 2018-10-23T11:26:40.235258Z 0 [Note] InnoDB: Starting crash recovery. 2018-10-23T11:26:40.615371Z 0 [Note] InnoDB: Removed temporary tablespace data file: "ibtmp1" 2018-10-23T11:26:40.615425Z 0 [Note] InnoDB: Creating shared tablespace for temporary tables 2018-10-23T11:26:40.615673Z 0 [Note] InnoDB: Setting file './ibtmp1' size to 12 MB. Physically writing the file full; Please wait ... 2018-10-23T11:26:40.692886Z 0 [Note] InnoDB: File './ibtmp1' size is now 12 MB. 2018-10-23T11:26:40.695499Z 0 [Note] InnoDB: 96 redo rollback segment(s) found. 96 redo rollback segment(s) are active. 2018-10-23T11:26:40.695537Z 0 [Note] InnoDB: 32 non-redo rollback segment(s) are active. 2018-10-23T11:26:40.697639Z 0 [Note] InnoDB: Waiting for purge to start 2018-10-23T11:26:40.748154Z 0 [Note] InnoDB: 5.7.23 started; log sequence number 2640584 2018-10-23T11:26:40.749929Z 0 [Note] InnoDB: Loading buffer pool(s) from /home/ushastry/sandboxes/rsandbox_5_7_23/node1/data/ib_buffer_pool 2018-10-23T11:26:40.750329Z 0 [Note] Plugin 'FEDERATED' is disabled. 2018-10-23T11:26:40.776690Z 0 [Note] InnoDB: Buffer pool(s) load completed at 181023 7:26:40 2018-10-23T11:26:40.784304Z 0 [Note] Recovering after a crash using mysql-bin 2018-10-23T11:26:40.784369Z 0 [Note] Starting crash recovery... 2018-10-23T11:26:40.784548Z 0 [Note] Crash recovery finished. 2018-10-23T11:26:40.819497Z 0 [Warning] Failed to set up SSL because of the following SSL library error: SSL context is not usable without certificate and private key 2018-10-23T11:26:40.819544Z 0 [Note] Server hostname (bind-address): '127.0.0.1'; port: 19025 2018-10-23T11:26:40.819611Z 0 [Note] - '127.0.0.1' resolves to '127.0.0.1'; 2018-10-23T11:26:40.819712Z 0 [Note] Server socket created on IP: '127.0.0.1'. 2018-10-23T11:26:40.991948Z 0 [Note] Slave: MTS group recovery relay log info based on Worker-Id 8, group_relay_log_name ./mysql-relay.000003, group_relay_log_pos 1320 group_master_log_name mysql-bin.000001, group_master_log_pos 5685 2018-10-23T11:26:41.003797Z 0 [ERROR] Error looking for file after ./mysql-relay.000004. 2018-10-23T11:26:41.022257Z 0 [ERROR] Slave: Failed to initialize the master info structure for channel ''; its record may still be present in 'mysql.slave_master_info' table, consider deleting it. 2018-10-23T11:26:41.022292Z 0 [ERROR] Failed to create or recover replication info repositories. 2018-10-23T11:26:41.022319Z 0 [Note] Some of the channels are not created/initialized properly. Check for additional messages above. You will not be able to start replication on those channels until the issue is resolved and the server restarted. 2018-10-23T11:26:41.353750Z 0 [Note] Event Scheduler: Loaded 0 events 2018-10-23T11:26:41.354431Z 0 [Note] /home/ushastry/opt/mysql/5.7.23/bin/mysqld: ready for connections. Version: '5.7.23-log' socket: '/tmp/mysql_sandbox19025.sock' port: 19025 MySQL Community Server (GPL)