Bug #96244 [GCS] The member was unable to join the group. Local port: 33061
Submitted: 18 Jul 7:25 Modified: 30 Sep 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: Bogdan Kecman CPU Architecture:Any
Tags: group replication, MySQL

[18 Jul 7:25] Dilip Padmanabhan
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
[23 Jul 12:38] Bogdan Kecman
Hi,

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

thanks
[24 Aug 1:00] Bugs System
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".
[28 Aug 9:09] Dilip Padmanabhan
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.
[28 Aug 9:13] Dilip Padmanabhan
Server-1

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

[28 Aug 9:13] Dilip Padmanabhan
Server-2

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

[30 Aug 11:58] Bogdan Kecman
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...
[1 Oct 1:00] Bugs System
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".
[2 Dec 14:28] Balazs Temesrekasi
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