Re: Mysql5.7.17 group replication add second server failed
Posted by:
zero yang
Date: December 28, 2016 08:16PM
HI. Thank you for your reply.
my.cnf of node 1:
[mysqld]
port = 3306
socket = /tmp/mysql.sock
user=mysql
basedir=/usr/local/mysql/
datadir=/usr/local/mysql/data
explicit_defaults_for_timestamp
server-id = 1
log-bin=mysql-bin
binlog-format = ROW
gtid-mode = ON
enforce-gtid-consistency = ON
log-slave-updates = ON
master-info-repository = TABLE
relay-log-info-repository = TABLE
binlog-checksum = NONE
transaction_write_set_extraction=XXHASH64
loose-group_replication_group_name="aaaaaaaa-aaaa-aaaa-aaaa-aaaaaaaaaaaa"
loose-group_replication_start_on_boot=off
loose-group_replication_local_address= "172.27.19.233:24901"
loose-group_replication_group_seeds= "172.27.19.233:24901,10.130.10.192:24901,10.134.128.85:24901"
loose-group_replication_ip_whitelist = "172.27.19.233,10.130.10.192,10.134.128.85"
loose-group_replication_bootstrap_group= off
loose-group_replication_single_primary_mode=FALSE
loose-group_replication_enforce_update_everywhere_checks= TRUE
[mysqldump]
quick
max_allowed_packet = 16M
error log of node 1:
2016-12-26T06:30:38.929185Z 0 [Note] --secure-file-priv is set to NULL. Operations related to importing and exporting data are disabled
2016-12-26T06:30:38.929282Z 0 [Note] /usr/local/mysql/bin/mysqld (mysqld 5.7.17-log) starting as process 2054 ...
2016-12-26T06:30:38.935604Z 0 [Note] InnoDB: PUNCH HOLE support not available
2016-12-26T06:30:38.935640Z 0 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
2016-12-26T06:30:38.935650Z 0 [Note] InnoDB: Uses event mutexes
2016-12-26T06:30:38.935657Z 0 [Note] InnoDB: GCC builtin __sync_synchronize() is used for memory barrier
2016-12-26T06:30:38.935665Z 0 [Note] InnoDB: Compressed tables use zlib 1.2.3
2016-12-26T06:30:38.935673Z 0 [Note] InnoDB: Using Linux native AIO
2016-12-26T06:30:38.935921Z 0 [Note] InnoDB: Number of pools: 1
2016-12-26T06:30:38.936029Z 0 [Note] InnoDB: Using CPU crc32 instructions
2016-12-26T06:30:38.937243Z 0 [Note] InnoDB: Initializing buffer pool, total size = 128M, instances = 1, chunk size = 128M
2016-12-26T06:30:38.946155Z 0 [Note] InnoDB: Completed initialization of buffer pool
2016-12-26T06:30:38.947978Z 0 [Note] InnoDB: If the mysqld execution user is authorized, page cleaner thread priority can be changed. See the man page of setpriority().
2016-12-26T06:30:38.959834Z 0 [Note] InnoDB: Highest supported file format is Barracuda.
2016-12-26T06:30:38.968501Z 0 [Note] InnoDB: Creating shared tablespace for temporary tables
2016-12-26T06:30:38.968579Z 0 [Note] InnoDB: Setting file './ibtmp1' size to 12 MB. Physically writing the file full; Please wait ...
2016-12-26T06:30:38.989246Z 0 [Note] InnoDB: File './ibtmp1' size is now 12 MB.
2016-12-26T06:30:38.990342Z 0 [Note] InnoDB: 96 redo rollback segment(s) found. 96 redo rollback segment(s) are active.
2016-12-26T06:30:38.990359Z 0 [Note] InnoDB: 32 non-redo rollback segment(s) are active.
2016-12-26T06:30:38.990662Z 0 [Note] InnoDB: Waiting for purge to start
2016-12-26T06:30:39.040782Z 0 [Note] InnoDB: 5.7.17 started; log sequence number 2545586
2016-12-26T06:30:39.040917Z 0 [Note] InnoDB: Loading buffer pool(s) from /data/mysql/data/ib_buffer_pool
2016-12-26T06:30:39.041124Z 0 [Note] Plugin 'FEDERATED' is disabled.
2016-12-26T06:30:39.042778Z 0 [Note] InnoDB: Buffer pool(s) load completed at 161226 14:30:39
2016-12-26T06:30:39.050005Z 0 [Note] Found ca.pem, server-cert.pem and server-key.pem in data directory. Trying to enable SSL support using them.
2016-12-26T06:30:39.050149Z 0 [ERROR] SSL error: Unable to get private key from 'server-key.pem'
2016-12-26T06:30:39.050166Z 0 [Warning] Failed to set up SSL because of the following SSL library error: Unable to get private key
2016-12-26T06:30:39.050178Z 0 [Note] Server hostname (bind-address): '*'; port: 3306
2016-12-26T06:30:39.050251Z 0 [Note] IPv6 is available.
2016-12-26T06:30:39.050266Z 0 [Note] - '::' resolves to '::';
2016-12-26T06:30:39.050289Z 0 [Note] Server socket created on IP: '::'.
2016-12-26T06:30:39.054430Z 0 [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=qsitil5-relay-bin' to avoid this problem.
2016-12-26T06:30:39.063358Z 0 [Note] Event Scheduler: Loaded 0 events
2016-12-26T06:30:39.063444Z 0 [Note] Executing 'SELECT * FROM INFORMATION_SCHEMA.TABLES;' to get a list of tables using the deprecated partition engine. You may use the startup option '--disable-partition-engine-check' to skip this check.
2016-12-26T06:30:39.063457Z 0 [Note] Beginning of list of non-natively partitioned tables
2016-12-26T06:30:39.075345Z 0 [Note] End of list of non-natively partitioned tables
2016-12-26T06:30:39.075455Z 0 [Note] /usr/local/mysql/bin/mysqld: ready for connections.
Version: '5.7.17-log' socket: '/tmp/mysql.sock' port: 3306 Source distribution
2016-12-26T06:30:42.026508Z 4 [Note] Access denied for user 'root'@'qsitil5_in' (using password: YES)
2016-12-26T06:30:54.890755Z 5 [Note] Plugin group_replication reported: 'Group communication SSL configuration: group_replication_ssl_mode: "DISABLED"'
2016-12-26T06:30:54.891009Z 5 [Warning] Plugin group_replication reported: '[GCS] Automatically adding IPv4 localhost address to the whitelist. It is mandatory that it is added.'
2016-12-26T06:30:54.891080Z 5 [Note] Plugin group_replication reported: '[GCS] SSL was not enabled'
2016-12-26T06:30:54.891102Z 5 [Note] Plugin group_replication reported: 'Initialized group communication with configuration: group_replication_group_name: "aaaaaaaa-aaaa-aaaa-aaaa-aaaaaaaaaaaa"; group_replication_local_address: "172.27.19.233:24901"; group_replication_group_seeds: "172.27.19.233:24901,10.130.10.192:24901,10.134.128.85:24901"; group_replication_bootstrap_group: true; group_replication_poll_spin_loops: 0; group_replication_compression_threshold: 1000000; group_replication_ip_whitelist: "172.27.19.233,10.130.10.192,10.134.128.85"'
2016-12-26T06:30:54.891676Z 7 [Note] 'CHANGE MASTER TO FOR CHANNEL 'group_replication_applier' executed'. Previous state master_host='<NULL>', master_port= 0, master_log_file='', master_log_pos= 4, master_bind=''. New state master_host='<NULL>', master_port= 0, master_log_file='', master_log_pos= 4, master_bind=''.
2016-12-26T06:30:54.893890Z 5 [Note] Plugin group_replication reported: 'Group Replication applier module successfully initialized!'
2016-12-26T06:30:54.893903Z 10 [Note] Slave SQL thread for channel 'group_replication_applier' initialized, starting replication in log 'FIRST' at position 0, relay log './qsitil5-relay-bin-group_replication_applier.000001' position: 4
2016-12-26T06:30:54.893907Z 5 [Note] Plugin group_replication reported: 'auto_increment_increment is set to 7'
2016-12-26T06:30:54.893927Z 5 [Note] Plugin group_replication reported: 'auto_increment_offset is set to 1'
2016-12-26T06:30:54.893994Z 0 [Note] Plugin group_replication reported: 'state 0 action xa_init'
2016-12-26T06:30:54.914524Z 0 [Note] Plugin group_replication reported: 'Successfully bound to 0.0.0.0:24901 (socket=48).'
2016-12-26T06:30:54.914563Z 0 [Note] Plugin group_replication reported: 'Successfully set listen backlog to 32 (socket=48)!'
2016-12-26T06:30:54.914573Z 0 [Note] Plugin group_replication reported: 'Successfully unblocked socket (socket=48)!'
2016-12-26T06:30:54.914607Z 0 [Note] Plugin group_replication reported: 'Ready to accept incoming connections on 0.0.0.0:24901 (socket=48)!'
2016-12-26T06:30:54.914615Z 0 [Note] Plugin group_replication reported: 'connecting to 172.27.19.233 24901'
2016-12-26T06:30:54.914747Z 0 [Note] Plugin group_replication reported: 'client connected to 172.27.19.233 24901 fd 49'
2016-12-26T06:30:54.914903Z 0 [Note] Plugin group_replication reported: 'connecting to 172.27.19.233 24901'
2016-12-26T06:30:54.914981Z 0 [Note] Plugin group_replication reported: 'client connected to 172.27.19.233 24901 fd 65'
2016-12-26T06:30:54.915110Z 0 [Note] Plugin group_replication reported: 'connecting to 172.27.19.233 24901'
2016-12-26T06:30:54.915187Z 0 [Note] Plugin group_replication reported: 'client connected to 172.27.19.233 24901 fd 67'
2016-12-26T06:30:54.915292Z 0 [Note] Plugin group_replication reported: 'connecting to 172.27.19.233 24901'
2016-12-26T06:30:54.915365Z 0 [Note] Plugin group_replication reported: 'client connected to 172.27.19.233 24901 fd 69'
2016-12-26T06:30:54.915470Z 0 [Note] Plugin group_replication reported: 'connecting to 172.27.19.233 24901'
2016-12-26T06:30:54.915541Z 0 [Note] Plugin group_replication reported: 'client connected to 172.27.19.233 24901 fd 71'
2016-12-26T06:30:54.915646Z 0 [Note] Plugin group_replication reported: 'connecting to 172.27.19.233 24901'
2016-12-26T06:30:54.915717Z 0 [Note] Plugin group_replication reported: 'client connected to 172.27.19.233 24901 fd 73'
2016-12-26T06:30:54.915847Z 0 [Note] Plugin group_replication reported: 'state 4257 action xa_net_boot'
2016-12-26T06:30:54.915863Z 0 [Note] Plugin group_replication reported: 'getstart group_id 4317e324'
2016-12-26T06:30:54.916050Z 0 [Note] Plugin group_replication reported: 'new state x_run'
2016-12-26T06:30:54.916101Z 0 [Note] Plugin group_replication reported: 'state 4330 action xa_net_boot'
2016-12-26T06:30:54.916110Z 0 [Note] Plugin group_replication reported: 'new state x_run'
2016-12-26T06:30:54.916131Z 0 [Note] Plugin group_replication reported: 'getstart group_id 4317e324'
2016-12-26T06:30:55.915653Z 0 [Note] Plugin group_replication reported: 'Starting group replication recovery with view_id 14827338559155649:1'
2016-12-26T06:30:55.915876Z 13 [Note] Plugin group_replication reported: 'Only one server alive. Declaring this server as online within the replication group'
2016-12-26T06:30:55.916355Z 0 [Note] Plugin group_replication reported: 'This server was declared online within the replication group'
2016-12-26T06:38:42.025374Z 0 [Note] Plugin group_replication reported: 'getstart group_id 4317e324'
2016-12-26T06:40:14.039546Z 0 [Note] Plugin group_replication reported: 'getstart group_id 4317e324'
2016-12-26T06:40:14.957262Z 0 [Note] Plugin group_replication reported: 'Marking group replication view change with view_id 14827338559155649:2'
2016-12-26T06:40:14.959046Z 0 [Note] Plugin group_replication reported: 'This server was not declared online since it is on status OFFLINE'
my.cnf of node 2:
[mysqld]
port = 3306
socket = /tmp/mysql.sock
user=mysql
basedir=/usr/local/mysql/
datadir=/usr/local/mysql/data
explicit_defaults_for_timestamp
server-id = 2
log-bin=mysql-bin
binlog-format = ROW
gtid-mode = ON
enforce-gtid-consistency = ON
log-slave-updates = ON
master-info-repository = TABLE
relay-log-info-repository = TABLE
binlog-checksum = NONE
transaction_write_set_extraction=XXHASH64
loose-group_replication_group_name="aaaaaaaa-aaaa-aaaa-aaaa-aaaaaaaaaaaa"
loose-group_replication_start_on_boot=off
loose-group_replication_local_address= "10.130.10.192:24901"
loose-group_replication_group_seeds= "172.27.19.233:24901,10.130.10.192:24901,10.134.128.85:24901"
loose-group_replication_ip_whitelist = "172.27.19.233,10.130.10.192,10.134.128.85"
loose-group_replication_bootstrap_group= off
loose-group_replication_single_primary_mode=FALSE
loose-group_replication_enforce_update_everywhere_checks= TRUE
[mysqldump]
quick
max_allowed_packet = 16M
error log of node 2:
2016-12-26T06:39:56.671692Z 0 [Note] --secure-file-priv is set to NULL. Operations related to importing and exporting data are disabled
2016-12-26T06:39:56.671795Z 0 [Note] /usr/local/mysql/bin/mysqld (mysqld 5.7.17-log) starting as process 20079 ...
2016-12-26T06:39:56.680505Z 0 [Note] InnoDB: PUNCH HOLE support not available
2016-12-26T06:39:56.680542Z 0 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
2016-12-26T06:39:56.680551Z 0 [Note] InnoDB: Uses event mutexes
2016-12-26T06:39:56.680559Z 0 [Note] InnoDB: GCC builtin __sync_synchronize() is used for memory barrier
2016-12-26T06:39:56.680566Z 0 [Note] InnoDB: Compressed tables use zlib 1.2.3
2016-12-26T06:39:56.680573Z 0 [Note] InnoDB: Using Linux native AIO
2016-12-26T06:39:56.680832Z 0 [Note] InnoDB: Number of pools: 1
2016-12-26T06:39:56.680945Z 0 [Note] InnoDB: Using CPU crc32 instructions
2016-12-26T06:39:56.682650Z 0 [Note] InnoDB: Initializing buffer pool, total size = 128M, instances = 1, chunk size = 128M
2016-12-26T06:39:56.693638Z 0 [Note] InnoDB: Completed initialization of buffer pool
2016-12-26T06:39:56.695830Z 0 [Note] InnoDB: If the mysqld execution user is authorized, page cleaner thread priority can be changed. See the man page of setpriority().
2016-12-26T06:39:56.708333Z 0 [Note] InnoDB: Highest supported file format is Barracuda.
2016-12-26T06:39:56.719834Z 0 [Note] InnoDB: Creating shared tablespace for temporary tables
2016-12-26T06:39:56.719917Z 0 [Note] InnoDB: Setting file './ibtmp1' size to 12 MB. Physically writing the file full; Please wait ...
2016-12-26T06:39:56.756822Z 0 [Note] InnoDB: File './ibtmp1' size is now 12 MB.
2016-12-26T06:39:56.757981Z 0 [Note] InnoDB: 96 redo rollback segment(s) found. 96 redo rollback segment(s) are active.
2016-12-26T06:39:56.757999Z 0 [Note] InnoDB: 32 non-redo rollback segment(s) are active.
2016-12-26T06:39:56.758258Z 0 [Note] InnoDB: Waiting for purge to start
2016-12-26T06:39:56.808374Z 0 [Note] InnoDB: 5.7.17 started; log sequence number 2546442
2016-12-26T06:39:56.808651Z 0 [Note] InnoDB: Loading buffer pool(s) from /data/mysql/data/ib_buffer_pool
2016-12-26T06:39:56.808696Z 0 [Note] Plugin 'FEDERATED' is disabled.
2016-12-26T06:39:56.810745Z 0 [Note] InnoDB: Buffer pool(s) load completed at 161226 14:39:56
2016-12-26T06:39:56.819071Z 0 [Note] Found ca.pem, server-cert.pem and server-key.pem in data directory. Trying to enable SSL support using them.
2016-12-26T06:39:56.819297Z 0 [Warning] CA certificate ca.pem is self signed.
2016-12-26T06:39:56.821848Z 0 [Note] Server hostname (bind-address): '*'; port: 3306
2016-12-26T06:39:56.821916Z 0 [Note] IPv6 is available.
2016-12-26T06:39:56.821930Z 0 [Note] - '::' resolves to '::';
2016-12-26T06:39:56.821953Z 0 [Note] Server socket created on IP: '::'.
2016-12-26T06:39:56.826616Z 0 [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=qsitil6-relay-bin' to avoid this problem.
2016-12-26T06:39:56.837033Z 0 [Note] Event Scheduler: Loaded 0 events
2016-12-26T06:39:56.837244Z 0 [Note] Executing 'SELECT * FROM INFORMATION_SCHEMA.TABLES;' to get a list of tables using the deprecated partition engine. You may use the startup option '--disable-partition-engine-check' to skip this check.
2016-12-26T06:39:56.837281Z 0 [Note] Beginning of list of non-natively partitioned tables
2016-12-26T06:39:56.849859Z 0 [Note] End of list of non-natively partitioned tables
2016-12-26T06:39:56.850004Z 0 [Note] /usr/local/mysql/bin/mysqld: ready for connections.
Version: '5.7.17-log' socket: '/tmp/mysql.sock' port: 3306 Source distribution
2016-12-26T06:40:11.707101Z 4 [Note] Plugin group_replication reported: 'Group communication SSL configuration: group_replication_ssl_mode: "DISABLED"'
2016-12-26T06:40:11.707360Z 4 [Warning] Plugin group_replication reported: '[GCS] Automatically adding IPv4 localhost address to the whitelist. It is mandatory that it is added.'
2016-12-26T06:40:11.707611Z 4 [Note] Plugin group_replication reported: '[GCS] SSL was not enabled'
2016-12-26T06:40:11.707636Z 4 [Note] Plugin group_replication reported: 'Initialized group communication with configuration: group_replication_group_name: "aaaaaaaa-aaaa-aaaa-aaaa-aaaaaaaaaaaa"; group_replication_local_address: "10.130.10.192:24901"; group_replication_group_seeds: "172.27.19.233:24901,10.130.10.192:24901,10.134.128.85:24901"; group_replication_bootstrap_group: false; group_replication_poll_spin_loops: 0; group_replication_compression_threshold: 1000000; group_replication_ip_whitelist: "172.27.19.233,10.130.10.192,10.134.128.85"'
2016-12-26T06:40:11.708345Z 6 [Note] 'CHANGE MASTER TO FOR CHANNEL 'group_replication_applier' executed'. Previous state master_host='<NULL>', master_port= 0, master_log_file='', master_log_pos= 4, master_bind=''. New state master_host='<NULL>', master_port= 0, master_log_file='', master_log_pos= 4, master_bind=''.
2016-12-26T06:40:11.711928Z 4 [Note] Plugin group_replication reported: 'Group Replication applier module successfully initialized!'
2016-12-26T06:40:11.711948Z 4 [Note] Plugin group_replication reported: 'auto_increment_increment is set to 7'
2016-12-26T06:40:11.711955Z 4 [Note] Plugin group_replication reported: 'auto_increment_offset is set to 2'
2016-12-26T06:40:11.711937Z 9 [Note] Slave SQL thread for channel 'group_replication_applier' initialized, starting replication in log 'FIRST' at position 0, relay log './qsitil6-relay-bin-group_replication_applier.000001' position: 4
2016-12-26T06:40:11.712220Z 0 [Note] Plugin group_replication reported: 'state 0 action xa_init'
2016-12-26T06:40:11.734264Z 0 [Note] Plugin group_replication reported: 'Successfully bound to 0.0.0.0:24901 (socket=49).'
2016-12-26T06:40:11.734308Z 0 [Note] Plugin group_replication reported: 'Successfully set listen backlog to 32 (socket=49)!'
2016-12-26T06:40:11.734316Z 0 [Note] Plugin group_replication reported: 'Successfully unblocked socket (socket=49)!'
2016-12-26T06:40:11.734355Z 0 [Note] Plugin group_replication reported: 'Ready to accept incoming connections on 0.0.0.0:24901 (socket=49)!'
2016-12-26T06:40:11.734372Z 0 [Note] Plugin group_replication reported: 'connecting to 10.130.10.192 24901'
2016-12-26T06:40:11.734516Z 0 [Note] Plugin group_replication reported: 'client connected to 10.130.10.192 24901 fd 50'
2016-12-26T06:40:11.735224Z 0 [Note] Plugin group_replication reported: 'connecting to 10.130.10.192 24901'
2016-12-26T06:40:11.735334Z 0 [Note] Plugin group_replication reported: 'client connected to 10.130.10.192 24901 fd 66'
2016-12-26T06:40:11.735890Z 0 [Note] Plugin group_replication reported: 'connecting to 10.130.10.192 24901'
2016-12-26T06:40:11.735984Z 0 [Note] Plugin group_replication reported: 'client connected to 10.130.10.192 24901 fd 68'
2016-12-26T06:40:11.736138Z 0 [Note] Plugin group_replication reported: 'connecting to 10.130.10.192 24901'
2016-12-26T06:40:11.736226Z 0 [Note] Plugin group_replication reported: 'client connected to 10.130.10.192 24901 fd 70'
2016-12-26T06:40:11.736381Z 0 [Note] Plugin group_replication reported: 'connecting to 10.130.10.192 24901'
2016-12-26T06:40:11.736466Z 0 [Note] Plugin group_replication reported: 'client connected to 10.130.10.192 24901 fd 72'
2016-12-26T06:40:11.736582Z 0 [Note] Plugin group_replication reported: 'connecting to 10.130.10.192 24901'
2016-12-26T06:40:11.736678Z 0 [Note] Plugin group_replication reported: 'client connected to 10.130.10.192 24901 fd 74'
2016-12-26T06:40:11.736793Z 0 [Note] Plugin group_replication reported: 'connecting to 172.27.19.233 24901'
2016-12-26T06:40:11.737004Z 0 [Note] Plugin group_replication reported: 'client connected to 172.27.19.233 24901 fd 76'
2016-12-26T06:40:13.036560Z 0 [Note] Plugin group_replication reported: 'state 4257 action xa_snapshot'
2016-12-26T06:40:13.036757Z 0 [Note] Plugin group_replication reported: 'new state x_recover'
2016-12-26T06:40:13.036771Z 0 [Note] Plugin group_replication reported: 'state 4277 action xa_complete'
2016-12-26T06:40:13.036901Z 0 [Note] Plugin group_replication reported: 'new state x_run'
2016-12-26T06:40:14.040952Z 0 [Note] Plugin group_replication reported: 'getstart group_id 4317e324'
2016-12-26T06:40:14.958794Z 0 [Note] Plugin group_replication reported: 'Starting group replication recovery with view_id 14827338559155649:2'
2016-12-26T06:40:14.959139Z 12 [Note] Plugin group_replication reported: 'Only one server alive. Declaring this server as online within the replication group'
2016-12-26T06:40:14.960508Z 0 [Note] Plugin group_replication reported: 'This server was declared online within the replication group'
Telnet the port 3306 and 24901 from each other is ok.There is no access control between these two server.