MySQL Bugs: #96244: [GCS] The member was unable to join the group. Local port: 33061

Bug #96244	[GCS] The member was unable to join the group. Local port: 33061
Submitted:	18 Jul 2019 7:25	Modified:	30 Sep 2019 11:58
Reporter:	Dilip Padmanabhan	Email Updates:
Status:	No Feedback	Impact on me:	None
Category:	MySQL Server: Group Replication	Severity:	S3 (Non-critical)
Version:	8.0.16	OS:	Ubuntu (Ubuntu 18.04 in Digital Ocean)
Assigned to:	MySQL Verification Team	CPU Architecture:	Any
Tags:	group replication, MySQL

Description:
Error Log:

2019-07-17T09:28:22.128204Z 0 [Warning] [MY-010068] [Server] CA certificate ca.pem is self signed.
2019-07-17T09:28:22.133538Z 0 [Warning] [MY-011810] [Server] Insecure configuration for --pid-file: Location '/tmp' in the path is accessible to all OS users. Consider choosing a different directory.
2019-07-17T09:28:22.173617Z 6 [System] [MY-013172] [Server] Received SHUTDOWN from user boot. Shutting down mysqld (Version: 8.0.13).
2019-07-17T09:28:22.174160Z 0 [System] [MY-010931] [Server] /usr/sbin/mysqld: ready for connections. Version: '8.0.13'  socket: '/tmp/tmp.OaTgB84drZ/mysqld.sock'  port: 3306  MySQL Community Server - GPL.
2019-07-17T09:28:24.135111Z 0 [System] [MY-010910] [Server] /usr/sbin/mysqld: Shutdown complete (mysqld 8.0.13)  MySQL Community Server - GPL.
2019-07-17T09:28:25.436085Z 0 [System] [MY-010116] [Server] /usr/sbin/mysqld (mysqld 8.0.13) starting as process 17794
2019-07-17T09:28:28.451968Z 0 [Warning] [MY-010068] [Server] CA certificate ca.pem is self signed.
2019-07-17T09:28:28.485203Z 0 [System] [MY-010931] [Server] /usr/sbin/mysqld: ready for connections. Version: '8.0.13'  socket: '/var/run/mysqld/mysqld.sock'  port: 3306  MySQL Community Server - GPL.
2019-07-17T09:28:28.579208Z 0 [System] [MY-011323] [Server] X Plugin ready for connections. Socket: '/var/run/mysqld/mysqlx.sock' bind-address: '::' port: 33060
2019-07-17T09:44:37.112317Z 0 [System] [MY-010910] [Server] /usr/sbin/mysqld: Shutdown complete (mysqld 8.0.13)  MySQL Community Server - GPL.
2019-07-17T09:44:37.589690Z 0 [System] [MY-010116] [Server] /usr/sbin/mysqld (mysqld 8.0.13) starting as process 17984
2019-07-17T09:44:38.711230Z 0 [Warning] [MY-010068] [Server] CA certificate ca.pem is self signed.
2019-07-17T09:44:38.719004Z 0 [Warning] [MY-000067] [Server] unknown variable 'loose-group_replication_bootstrap_group=OFF'.
2019-07-17T09:44:38.719057Z 0 [Warning] [MY-000067] [Server] unknown variable 'loose-group_replication_start_on_boot=OFF'.
2019-07-17T09:44:38.719079Z 0 [Warning] [MY-000067] [Server] unknown variable 'loose-group_replication_ssl_mode=REQUIRED'.
2019-07-17T09:44:38.719099Z 0 [Warning] [MY-000067] [Server] unknown variable 'loose-group_replication_recovery_use_ssl=1'.
2019-07-17T09:44:38.719120Z 0 [Warning] [MY-000067] [Server] unknown variable 'loose-group_replication_group_name=4eb49235-0673-4125-8eee-5bd117774bb4'.
2019-07-17T09:44:38.719139Z 0 [Warning] [MY-000067] [Server] unknown variable 'loose-group_replication_ip_whitelist=139.59.10.92,139.59.30.212'.
2019-07-17T09:44:38.719159Z 0 [Warning] [MY-000067] [Server] unknown variable 'loose-group_replication_group_seeds=139.59.10.92:33061,139.59.30.212:33061'.
2019-07-17T09:44:38.719178Z 0 [Warning] [MY-000067] [Server] unknown variable 'loose-group_replication_single_primary_mode=OFF'.
2019-07-17T09:44:38.719198Z 0 [Warning] [MY-000067] [Server] unknown variable 'loose-group_replication_enforce_update_everywhere_checks=ON'.
2019-07-17T09:44:38.719215Z 0 [Warning] [MY-000067] [Server] unknown variable 'loose-group_replication_local_address=139.59.10.92:33061'.
2019-07-17T09:44:38.738841Z 0 [System] [MY-010931] [Server] /usr/sbin/mysqld: ready for connections. Version: '8.0.13'  socket: '/var/run/mysqld/mysqld.sock'  port: 3306  MySQL Community Server - GPL.
2019-07-17T09:44:38.851186Z 0 [System] [MY-011323] [Server] X Plugin ready for connections. Socket: '/var/run/mysqld/mysqlx.sock' bind-address: '::' port: 33060
2019-07-17T09:46:34.876003Z 8 [Warning] [MY-010604] [Repl] 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=mysql-02-relay-bin' to avoid this problem.
2019-07-17T09:46:34.893200Z 8 [System] [MY-010597] [Repl] 'CHANGE MASTER TO FOR CHANNEL 'group_replication_recovery' executed'. Previous state master_host='', master_port= 3306, master_log_file='', master_log_pos= 4, master_bind=''. New state master_host='', master_port= 3306, master_log_file='', master_log_pos= 4, master_bind=''.
2019-07-17T09:47:59.650509Z 8 [Warning] [MY-011735] [Repl] Plugin group_replication reported: '[GCS] Automatically adding IPv4 localhost address to the whitelist. It is mandatory that it is added.'
2019-07-17T09:47:59.970289Z 10 [System] [MY-010597] [Repl] 'CHANGE MASTER TO FOR CHANNEL 'group_replication_applier' executed'. Previous state master_host='', master_port= 3306, 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=''.
2019-07-17T09:48:00.074005Z 0 [Warning] [MY-011735] [Repl] Plugin group_replication reported: '[GCS] read failed'
2019-07-17T09:48:00.083921Z 0 [ERROR] [MY-011735] [Repl] Plugin group_replication reported: '[GCS] The member was unable to join the group. Local port: 33061'
2019-07-17T09:49:00.012908Z 8 [ERROR] [MY-011640] [Repl] Plugin group_replication reported: 'Timeout on wait for view after joining group'
2019-07-17T09:49:00.012979Z 8 [ERROR] [MY-011735] [Repl] Plugin group_replication reported: '[GCS] The member is leaving a group without being on one.'
2019-07-17T09:50:49.638533Z 14 [Warning] [MY-011735] [Repl] Plugin group_replication reported: '[GCS] Automatically adding IPv4 localhost address to the whitelist. It is mandatory that it is added.'
2019-07-17T09:50:49.641806Z 16 [System] [MY-010597] [Repl] '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=''.
2019-07-17T09:50:49.727011Z 0 [Warning] [MY-011735] [Repl] Plugin group_replication reported: '[GCS] read failed'
2019-07-17T09:50:49.753651Z 0 [ERROR] [MY-011735] [Repl] Plugin group_replication reported: '[GCS] The member was unable to join the group. Local port: 33061'
2019-07-17T09:51:49.700996Z 14 [ERROR] [MY-011640] [Repl] Plugin group_replication reported: 'Timeout on wait for view after joining group'
2019-07-17T09:51:49.701108Z 14 [ERROR] [MY-011735] [Repl] Plugin group_replication reported: '[GCS] The member is leaving a group without being on one.'

How to repeat:
Steps: https://www.digitalocean.com/community/tutorials/how-to-configure-mysql-group-replication-...
Ubuntu VERSION="18.04.2 LTS (Bionic Beaver)"
Mysql: 8.0.16
Cloud Digital Ocean

Hi,

Can you reproduce this with 8.0.17, I'm not able to reproduce this with 8.0.17

thanks

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".

I tried to test in Digital Ocean Cloud with Ubuntu 18.04 servers and mysql 8.0.17, still the same issue. Will be uploading the error log and steps followed.

Server-1

Attachment: Mysql-Server1.txt (text/plain), 13.45 KiB.

Server-2

Attachment: Mysql-Server2.txt (text/plain), 17.64 KiB.

Hi,

I cannot reproduce this using bare metal and following Oracle manual. I really can't say what's going on on digital ocean.

Did you follow one of the following methods of setting up Innodb Cluster / GR

https://dev.mysql.com/doc/refman/5.7/en/mysql-innodb-cluster-sandbox-deployment.html

https://dev.mysql.com/doc/refman/5.7/en/mysql-innodb-cluster-production-deployment.html

https://mysqlserverteam.com/mysql-innodb-cluster-setting-up-a-real-world-cluster/

https://dev.mysql.com/doc/refman/8.0/en/group-replication-deploying-in-single-primary-mode...

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".

Hello,
version 8.0.18 the bug still exists:
MySQL is running with the mysqld_safe daemon

 

After killing the process with KILL -9 the network sockets cannot be closed quick enough.

netstat -anp | grep 33301

(Not all processes could be identified, non-owned process info

will not be shown, you would have to be root to see it all.)

tcp        1      0 10.186.227.197:20570    10.186.227.197:33301    CLOSE_WAIT  42457/mysqld

tcp        0      0 10.186.227.197:20448    10.186.227.197:33301    TIME_WAIT   -

tcp        0      0 10.186.227.197:33301    10.186.227.197:20570    FIN_WAIT2   -

 

Killing the process again the sockets are being released:

 

[host testcluster]$ kill -9 42457

[host testcluster]$ ./bin/mysqld_safe: line 199: 42457 Killed                  env MYSQLD_PARENT_PID=40378 env MYSQLD_PARENT_PID=40378 env MYSQLD_PARENT_PID=40378 env MYSQLD_PARENT_PID=40378 nohup /u00/app/mysql/product/mysql-commercial-8.0.18/bin/mysqld --defaults-file=/u00/app/mysql/startup/testcluster/my.cnf --basedir=/u00/app/mysql/product/mysql-commercial-8.0.18 --datadir=/u01/data/testcluster/data --plugin-dir=/u00/app/mysql/product/mysql-commercial-8.0.18/lib/plugin --log-error=/u00/app/mysql/logs/testcluster/testcluster_error.log --pid-file=/u00/app/mysql/startup/testcluster/testcluster.pid --socket=/u00/app/mysql/startup/testcluster/testcluster.sock --port=3330 < /dev/null >> /u00/app/mysql/logs/testcluster/testcluster_error.log 2>&1 >> /u00/app/mysql/logs/testcluster/testcluster_error.log 2>&1 >> /u00/app/mysql/logs/testcluster/testcluster_error.log 2>&1 >> /u00/app/mysql/logs/testcluster/testcluster_error.log 2>&1

2019-12-02T14:13:58.194204Z mysqld_safe Number of processes running now: 0

2019-12-02T14:13:58.199211Z mysqld_safe mysqld restarted

 

[host testcluster]$ netstat -anp | grep 33301

(Not all processes could be identified, non-owned process info

will not be shown, you would have to be root to see it all.)

tcp        0      0 0.0.0.0:33301           0.0.0.0:*               LISTEN      42561/mysqld

tcp        0      0 10.186.227.197:33301    10.186.227.197:20744    ESTABLISHED 42561/mysqld

tcp        0      0 10.186.227.197:33301    10.186.227.198:46338    ESTABLISHED 42561/mysqld

tcp        0      0 10.186.227.197:20744    10.186.227.197:33301    ESTABLISHED 42561/mysqld

tcp        0      0 10.186.227.197:33301    10.186.227.216:31374    ESTABLISHED 42561/mysqld

tcp        0      0 10.186.227.197:19622    10.186.227.198:33301    ESTABLISHED 42561/mysqld

tcp        0      0 10.186.227.197:35764    10.186.227.216:33301    ESTABLISHED 42561/mysqld

tcp        0      0 10.186.227.197:20448    10.186.227.197:33301    TIME_WAIT   -

tcp        0      0 10.186.227.197:33301    10.186.227.197:20570    TIME_WAIT   -

 

2019-12-02T14:13:42.750121Z 0 [Note] [MY-010855] [Server] Recovering after a crash using /u00/app/mysql/binlogs/testcluster/testcluster-bin

2019-12-02T14:13:42.750348Z 0 [System] [MY-010229] [Server] Starting crash recovery...

2019-12-02T14:13:42.761718Z 0 [System] [MY-010232] [Server] Crash recovery finished.

2019-12-02T14:13:42.772733Z 0 [Note] [MY-012487] [InnoDB] DDL log recovery : begin

2019-12-02T14:13:42.773028Z 0 [Note] [MY-012488] [InnoDB] DDL log recovery : end

2019-12-02T14:13:42.773445Z 0 [Note] [MY-011946] [InnoDB] Loading buffer pool(s) from /u01/data/testcluster/data/ib_buffer_pool

2019-12-02T14:13:42.774270Z 0 [Note] [MY-011946] [InnoDB] Buffer pool(s) load completed at 191202 15:13:42

2019-12-02T14:13:42.781153Z 0 [Note] [MY-012922] [InnoDB] Waiting for purge to start

2019-12-02T14:13:42.844038Z 0 [Note] [MY-010306] [Server] Skipping generation of SSL certificates as --auto_generate_certs is set to OFF.

2019-12-02T14:13:42.846862Z 0 [Note] [MY-010308] [Server] Skipping generation of RSA key pair through --sha256_password_auto_generate_rsa_keys as key files

are present in data directory.

 

2019-12-02T14:13:42.919335Z 9 [System] [MY-010597] [Repl] '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_lo

g_pos= 4, master_bind=''.

2019-12-02T14:13:42.942930Z 2 [Note] [MY-011670] [Repl] Plugin group_replication reported: 'Group Replication applier module successfully initialized!'

2019-12-02T14:13:42.943053Z 13 [Note] [MY-010581] [Repl] Slave SQL thread for channel 'group_replication_applier' initialized, starting replication in log '

FIRST' at position 0, relay log '/u00/app/mysql/relay/testcluster/testcluster-relay-bin-group_replication_applier.000011' position: 4

2019-12-02T14:13:42.959683Z 0 [Note] [MY-011240] [Server] Plugin mysqlx reported: 'Using SSL configuration from MySQL Server'

2019-12-02T14:13:42.961042Z 0 [Note] [MY-011243] [Server] Plugin mysqlx reported: 'Using OpenSSL for TLS connections'

2019-12-02T14:13:42.979825Z 0 [Note] [MY-011323] [Server] Plugin mysqlx reported: 'X Plugin ready for connections. bind-address: '0.0.0.0' port: 33060'

2019-12-02T14:13:42.979875Z 0 [Note] [MY-011323] [Server] Plugin mysqlx reported: 'X Plugin ready for connections. socket: '/tmp/mysqlx.sock''

2019-12-02T14:13:42.979896Z 0 [System] [MY-011323] [Server] X Plugin ready for connections. Socket: '/tmp/mysqlx.sock' bind-address: '0.0.0.0' port: 33060

2019-12-02T14:13:43.113032Z 0 [Note] [MY-011735] [Repl] Plugin group_replication reported: '[GCS] Unable to create socket v6(socket=-1, errno=97)!'

2019-12-02T14:13:43.115669Z 0 [Note] [MY-011735] [Repl] Plugin group_replication reported: '[GCS] XCom protocol version: 7'

2019-12-02T14:13:43.115696Z 0 [Note] [MY-011735] [Repl] Plugin group_replication reported: '[GCS] XCom initialized and ready to accept incoming connections

on port 33301'

2019-12-02T14:13:43.331377Z 0 [ERROR] [MY-011735] [Repl] Plugin group_replication reported: '[GCS] Error connecting to all peers. Member join failed. Local

port: 33301'

2019-12-02T14:13:43.399700Z 0 [ERROR] [MY-011735] [Repl] Plugin group_replication reported: '[GCS] The member was unable to join the group. Local port: 3330

1'

2019-12-02T14:13:58.194204Z mysqld_safe Number of processes running now: 0

2019-12-02T14:13:58.199211Z mysqld_safe mysqld restarted